Parellel Loop and Nlog

Question

I perform some operations on files in a parallel.for Loop for which a log is created. But I need to know which operation created a particular log-entry. I tried to use the {ThreadID} in my nlog-config, but the threadID is reused by the parallel.for loop so that there seems to be no unique identifier. Any Suggestions how to give every file a unique log-identifier?

Basic code:

Private Sub DoParallel
 Private Logger As NLog.Logger = NLog.LogManager.GetCurrentClassLogger 
 Dim ListOfFolder as New List(of String)
 ListOfFolder.add("C:\Test.txt")

 Parallel.ForEach(listOfFolders, Sub(elem As String)
     logger.warn("Doing stuff, need to know on which elem it is done")
  End Sub)
End Sub

Nlog Config:

 layout="${threadid} | ${time} | ${level:uppercase=true} | ${logger} | ${message} | ${exception}"

score 3 · Accepted Answer · edited May 23 '17 at 11:56

You could try using Trace.CorrelationManager.ActivityId. You can set a value and then use a custom NLog LayoutRenderer to render that value to the output log. You can find an example of a LayoutRenderer that does this here on SO. Look about in the middle of the top answer.

Here is the code for the LayoutRender from that post (note that it was written against NLog 1.0, not NLog 2.0. It should not be hard to update).

[LayoutRenderer("ActivityId")]
class ActivityIdLayoutRenderer : LayoutRenderer
{
  int estimatedSize = Guid.Empty.ToString().Length;

  protected override void Append(StringBuilder builder, LogEventInfo logEvent)
  {
    builder.Append(Trace.CorrelationManager.ActivityId);
  }

  protected override int GetEstimatedBufferSize(LogEventInfo logEvent)
  {
    return estimatedSize;
  }
}

Your NLog.config would look something like this:

Tell NLog where your NLog extensions are located:

<extensions>
    <add assembly="MyNLogExtensions"/>
</extensions>

layout="${threadid} | ${ActivityId} | ${time} | ${level:uppercase=true} | ${logger} | ${message} | ${exception}"

Using your original sample code, you could log something like this:

Private Sub DoParallel
 Private Logger As NLog.Logger = NLog.LogManager.GetCurrentClassLogger 
 Dim ListOfFolder as New List(of String)
 ListOfFolder.add("C:\Test.txt")

 Trace.CorrelationManager.ActivityId = Guid.Empty;
 Parallel.ForEach(listOfFolders, Sub(elem As String)
     Trace.CorrelationManager.ActivityId = Guid.NewGuid();
     logger.warn("Doing stuff, need to know on which elem it is done")
     Trace.CorrelationManager.ActivityId = Guid.Empty;
  End Sub)
End Sub

This should uniquely identify each logging statement and, if you had more lines of code in your action, all of the logging statements from a given execution of the action would be tagged with the same guid.

If this approach works for you, you could easily wrap the ActivityId setting/unsetting in an IDisposable class and use the using statement to automate the process.

Please forgive the C#:

public class ActivityIdContext : IDisposable
{
  Guid oldActivityId;

  public ActivityIdContext(Guid id)
  {
    oldActivityId = Trace.CorrelationManager.ActivityId;
    Trace.CorrelationManager.ActivityId = Guid.NewGuid();
  }

  public ActivityIdContext() : this(Guid.NewGuid()) { }

  public Dispose()
  {
    Trace.CorrelationManager.ActivityId = oldActivityId;
  }
}

Then, you could enclose the body of the Parallel.ForEach action to do something like this (again, in C#)

Parallel.ForEach(listOfFolders, () =>
{
  using(new ActivityIdContext())
  {
    logger.Warn("Hello!  I hope the ActivityId helps!");
  }
});

Wow that looks great! My workday finished for today, but I will try your approach tomorrow morning. I am totally impressed by your work, thank you very much! — Christian Sauer, Oct 16 '12 at 15:53

Parellel Loop and Nlog

1 Answers1