Skip to content
Rolf Kristensen edited this page Sep 23, 2023 · 36 revisions

NLog has been created with performance in mind, and is optimized to have minimal impact on the actual application-code. It can easily handle 500.000 messages/sec, but if using NLog in ways not intended, then you might not get the expected performance.

Logger optimizations

When using the NLog Logger, then there are some things that affects optimal performance:

  • Avoid constantly calling LogManager.GetLogger() and LogManager.GetCurrentClassLogger() by using static readonly variables.
  • Defer message-formatting by not using string.format and string interpolation (Ex $"Hello {world}") but pass the arguments to the log method.
  • If multiple threads are logging to the same NLog Target (file / console), then it is recommended to apply the AsyncWrapper.
  • Conditional logging is recommended when creation of the log-message has an overhead, and logging is not always turned on.

Defer message-formatting

NLog has a strong focus on being able to defer the message-formatting. When using <targets async="true"> or AsyncWrapper target then the formatting and writing can be done by a background-thread. The async message-formatting requires that all parameters are immutable. To ensure that they don't change after having called the Logger (Ex logging an object and disposing the object afterwards should not log a disposed object).

The NLog Logger (During the creation of LogEventInfo) checks whether all parameters are immutable / primitive. If one is complex-object, then message-formatting is not deferred. When having more than 5 parameters then it will skip the performance optimization, because checking the immutable state of the parameters has a cost.

Notice when using Microsoft Extension Logging with NLog, then NLog is not able to perform this optimization, because Microsoft Extension Logging handles the message-parsing and -formatting upfront.

Layout configuration

Many NLog LayoutRenderers have little overhead, and allows deferring the layout logic to background-thread when enabled with <targets async="true"> (Activates AsyncWrapper target).

But if using NLog LayoutRenders that requires context capture of the current application-thread like ${threadid}, then the application-thread will get extra overhead to perform this context capture. This also happens with most ${aspnet-request}-layout-renderers as they have to extract values from the active HttpContext. If performance is very important and wants to make most use of the async background-thread, then one should focus on using ${longdate}, ${logger}, ${level}, ${message} and ${event-properties}.

One should be careful with using ${callsite} and ${stacktrace} that outputs the call-site of the application-thread, because NLog makes the application-thread capture its current StackTrace, which is very expensive. NLog 5.0 introduces a new fluent Logger-API, that support caller-member-attributes, so the overhead from using ${callsite} is reduced a lot.

Conditional logging

NLog Logger has very little overhead when LogLevel is not enabled for any targets. But it might be noticeable if running in a tight loop and doing almost nothing, besides calling NLog Logger.

If having a complex logging statement, then one can consider checking if LogLevel is enabled before executing it:

if (Logger.IsDebugEnabled)
    Logger.Debug(GenerateMassiveLogEvent());

Starting of NLog 4.0 it’s possible to only include the Trace and Debug call with a debug release. Instead of:

Logger.Debug("entering method {0}", methodname);

Use:

Logger.ConditionalDebug("entering method {0}", methodname);

This call will be removed by the .Net compiler if the DEBUG conditional compilation symbol is not set – default for release build.

InternalLogger overhead

NLog Internal Logging is very useful for troubleshooting. To be alerted about potential logging issues, then one can enable internalLogLevel="Warn" to get warnings and errors.

During troubleshooting sessions then one might use internalLogLevel="Trace", but make sure to turn it off again when issue has been resolved. The InternalLogger is not written for performance, and will give a significant performance hit.

Automatic Extension Loading

NLog 4.0 automatically scans for assemblies that contains extensions for NLog at initial startup. This will automatically trigger loading of debugging symbols. This will be give the experience that NLog slows down the application startup.

NLog 5.0 no longer scans for assemblies at startup because of the startup overhead, and also because it doesn't work with the new csproj <packagereference>.

To skip the NLog assembly scan, then execute this statement before loading NLog Config or creating NLog Logger:

NLog.Config.ConfigurationItemFactory.Default = new NLog.Config.ConfigurationItemFactory(typeof(NLog.ILogger).GetTypeInfo().Assembly);

Visual Studio Debugger pauses during NLog initialization

Visual Studio is slow the first time when debugging application and having configured to load relevant debug symbol information.

To avoid these pauses then one can configure Visual Studio to 'Enable Just My Code`

It is a checkbox in Visual Studio Options. See Just my Code

File Logging Performance

Single process applications (in single AppDomain) can optimize performance by configuring the FileTarget attributes:

  • keepFileOpen = True
  • concurrentwrites = False

See also FileTarget - Performance

To avoid the blocking file write operation, then one can consider to wrap the FileTarget within a AsyncWrapper (Very important if using keepFileOpen = False). This will also optimize the writing to disk, as it will be done in batches. Be careful as the default behavior is to discard log operations if they come fast. So it is recommended to change the overflow-policy for non-network targets:

<targets>
   <default-wrapper xsi:type="AsyncWrapper" overflowAction="Block" />

   ... Your File Targets Here ...
</targets>

Remember to Flush is very important, to ensure background threads have completed writing before application exit.

Clone this wiki locally