October 4, 2013

How to configure NLog time source

NLog 2.1 added new feature that allows you to specify how NLog calculates timestamps in log messages. It allows you to choose between 1ms and 16ms accuracy and between UTC and local time.

I've developed the time source functionality after I have discovered that the default NLog timestamps are limited to 16ms accuracy even on systems configured to use 1ms system timer. Even after my changes, the default NLog time source still returns local time with 16ms accuracy. Here I will show you how to use time sources to get higher accuracy and also how to use the faster UTC time. Separate article describes how to create custom time sources.

How to configure Windows for 1ms time accuracy


Default timer accuracy on Windows is 16ms. This is good for battery life. Real-time and multimedia applications can use timeBeginPeriod Win32 API to increase timer accuracy to 1ms. The increased accuracy lasts until such application exits or calls timeEndPeriod.

XML configuration


In order to configure NLog to make use of the higher timer accuracy, you have to add one line into your NLog XML configuration:

<nlog>
    <time type='AccurateLocal' />
    ...
</nlog>

By default, NLog uses DateTime.Now to get current time, which is slow and it might be undesirable even though formatters can later convert the time to UTC. In order to make NLog get time from the fast DateTime.UtcNow with 16ms accuracy, you can use this configuration:

<nlog>
    <time type='FastUTC' />
    ...
</nlog>

In order to get both accurate and UTC time, use the following:

<nlog>
    <time type='AccurateUTC' />
    ...
</nlog>

You get the idea. Now how do we configure it in code?

Runtime configuration


You can configure millisecond accurate time, equivalent to AccurateLocal in XML configuration, by inserting the following line somewhere into your NLog initialization code before any log messages are printed:

TimeSource.Current = new AccurateLocalTimeSource();

In order to use UTC time with default 16ms accuracy, equivalent to FastUTC in XML configuration, use the following:

TimeSource.Current = new FastUtcTimeSource();

To get both accurate time and UTC time, equivalent to AccurateUTC in XML configuration, use the following:

TimeSource.Current = new AccurateUtcTimeSource();

Summary


Here are the predefined time sources and their semantics:

XML Runtime configuration Time Accuracy Speed
FastLocal FastLocalTimeSource local 16ms fastest
FastUTC FastUtcTimeSource UTC 16ms fastest
AccurateLocal AccurateLocalTimeSource local 1ms slow
AccurateUTC AccurateUtcTimeSource UTC 1ms fast

Enjoy!

5 comments:

  1. Thanks for this, especially like the summary table at the end :D

    ReplyDelete
  2. Could you drop some light on why AccurateUTC is fast and AccurateLocal is slow?

    ReplyDelete
  3. DateTime.UtcNow is faster than DateTime.Now, because DateTime.Now performs some expensive time zone translation. AccurateUTC inherits this performance advantage.

    ReplyDelete
  4. How does FastLocal work ? Since i am trying to work with Archiving based on "Day" ; To test the same when i change the Date Time still it doesn't Archive; But when the Archive period is "Hour" or "Minute" the DateTime change of the System does apply.

    ReplyDelete
  5. Bhuvin, FastLocal should behave exactly the same as the original hard-coded time source. If it doesn't work, there's likely a bug in the archiving code rather than the time source code.

    ReplyDelete