58

What should the expected overhead be for logging? I have tried this example

 private class Person
 {
    private static Logger logger = LogManager.GetCurrentClassLogger();
    public string Name { get; private set; }
    public Person(string name)
       {
           Name = name;
           logger.Info("New person created with name {0}", name);
       }
  }

  List<Person> people = new List<Person>();
  for (int i = 0; i < MAXTEST; i++)
  {
      people.Add(new Person(i.ToString()));
  }

With MAXTEST values of 100,500,1000, 5000

Results in MAXTEST,noLogging, Logging

100,  25ms, 186ms    
500,  33ms, 812ms    
1000, 33ms, 1554ms
5000, 33ms, 7654ms

Granted one would probably never log this excessive amount, but it this the performance hit one would expect?

I have also tried using the asyncwrapper in the config

 <target name="asyncFile" xsi:type="AsyncWrapper">
   <target name="file" xsi:type="File" fileName="${basedir}/log.txt" />
 </target>
wonea
  • 4,783
  • 17
  • 86
  • 139
Eric
  • 3,027
  • 6
  • 29
  • 34

2 Answers2

99

You only need to add the async attribute to your targets element:

<targets async="true">
        <target name="file" xsi:type="File" fileName="${basedir}/log.txt" />

instead of

<targets>
    <target name="asyncFile" xsi:type="AsyncWrapper">
        <target name="file" xsi:type="File" fileName="${basedir}/log.txt" />
    </target>

I guess I didn't get that far into the documentation ;-)

Asynchronous target wrapper allows the logger code to execute more quickly, by queueing messages and processing them in a separate thread. You should wrap targets that spend a non-trivial amount of time in their Write() method with asynchronous target to speed up logging. Because asynchronous logging is quite a common scenario, NLog supports a shorthand notation for wrapping all targets with AsyncWrapper. Just add async="true" to the element in the configuration file. ... your targets go here ...

Keep in mind that using async logging can cause certain messages to be discarded. This is by design.


ref: https://github.com/nlog/NLog/wiki/AsyncWrapper-target#async-attribute-and-asyncwrapper

Async attribute and AsyncWrapper

Don't combine the Async attribute and AsyncWrapper. This will only slow down processing and will behave unreliably.

Async attribute will discard by default

The async attribute is a shorthand for:

xsi:type="AsyncWrapper overflowAction="Discard" queueLimit="10000" batchSize="100" timeToSleepBetweenBatches="50"

ROY
  • 8,800
  • 1
  • 17
  • 13
Eric
  • 3,027
  • 6
  • 29
  • 34
  • 4
    How much of a difference did it make? Can you post the times to compare to your first set of results? – Jeff Ogata Oct 06 '10 at 00:02
  • 32
    it ended up being ~44ms for 5000 with logging. Regards – Eric Oct 06 '10 at 02:50
  • Surely if you add `` *instead* of e.g. `` you will no longer have an `asyncFile` target. I have edited your answer to clear that up. – ProfK Feb 05 '17 at 09:50
  • 8
    This answer now shows a bad practice, it is not recommended to use both an AsyncWrapper with async=true https://github.com/nlog/NLog/wiki/AsyncWrapper-target#async-attribute-and-asyncwrapper – Sander Kouwenhoven Apr 13 '17 at 08:24
  • 1
    Also if you put in a lot of messages at once, NLog async by default will *drop* messages. https://github.com/NLog/NLog/wiki/AsyncWrapper-target#async-attribute-will-discard-by-default The correct way to prevent loss of messages is detailed in https://github.com/NLog/NLog/issues/1652, in short, use an AsyncWrapper and set the overflowAction to Block or Grow. – Colin Feb 11 '20 at 04:21
25

For anyone who needs to lose this overhead and is configuring by code, it doesn't look like you can set all targets to asynchronous by default - you have to define it per-target:

// Set up asynchronous database logging assuming dbTarget is your existing target
AsyncTargetWrapper asyncWrapper = new AsyncTargetWrapper(dbTarget);
config.AddTarget("async", asyncWrapper);

// Define rules
LoggingRule rule1 = new LoggingRule("*", LogLevel.Trace, asyncWrapper);
config.LoggingRules.Add(rule1);

Be wary that by default if you queue up too many log items it will just drop items - look at OverflowAction = AsyncTargetWrapperOverflowAction.Block to go back to synchronous behaviour.

Rob Church
  • 6,783
  • 3
  • 41
  • 46
  • This is what i was looking for and thanks for the heads up on the OverflowAction. – YetAnotherDeveloper Sep 04 '14 at 19:39
  • 2
    Also be wary of `AsyncTargetWrapperOverflowAction.Block` if you are backing up on logging then it is likely that your system might already be stressed. Forcing the logging to block will further hamper your performance. Perhaps it is better to drop log messages than to stop processing requests. – Lee Jensen May 15 '15 at 14:10
  • I am writing to a target database. In my ```targets``` section, I have marked ```async``` as ```true```. Do I still need to write code to my web service to make logging async or framework takes care of it? – tRuEsAtM Aug 11 '17 at 17:19
  • @Sameer you are good to go. you read the documentation enough and already using the shortcut **async="true"** – Ahmed Alejo Sep 03 '17 at 17:35