Nlog not writing all lines into File in Parallel Loop

Question

I am using Nlog As per requirement I am processing few thousand records in Parallel loop

For each item After multiple operations in specifc order (Pipe Fliter pattern) I want to write specifc records (which are failed to load into datastore) in to a Output folder.

This Output folder is not a {basedir} but a specific to each client so I am using nlog and nlog Variable and assoicated configuration as below to write values into file for multithreaded application.

In Config file

<variable name="outPutFileFullName" value=""/>

<target xsi:type="File" name="OutPutFile" fileName="${mdc:item=outPutFileFullName}"
        layout="${message}"/>

<logger name ="ABC" 
 level="Info" writeTo="OutPutFile"></logger>

In Code

_loggingService.SetMappedDiagnosticsContext("outPutFileFullName", outPutFolderFile);


 Parallel.ForEach(allItems
               itemLine =>
     {
       itemLine.OutPutFileFullName = outPutFolderFile;
       var pipeLine = new PipeLine<TEST>();
       pipeLine.Register(new Operation1<TEST>(_loggingService))
       .Register(new Operation2<TEST>(_loggingService))
     .Register(new Operation3<TEST>(_loggingService))
      .Execute(itemLine);
   });

In operation 3 I have a simple method

 private  void WriteToFileFromObject(Test obj)
 {
   LoggingService.Info(obj.FileLineNumber.ToString());
 }

I am expecting this process to write 100 records but it is only writing 17 records always but not same and not in specific order.

If I change fileName="${mdc:item=outPutFileFullName}" in config file to a constant value like fileName="${basedir}/logs/Test.log" then all 100 records are written to file. Any Idea Why?

score 2 · Accepted Answer · edited May 23 '17 at 10:33

MappedDiagnosticsContext uses thread local storage. Parallel.ForEach will use other threads/tasks, which will not have access to the value that you put in the MappedDiagnosticsContext (since that is local to a specific thread). If you are only setting this value once for the application, then maybe you could use the GlobalDiagnosticsContext.

I suspect that the 17 items that are being written are from executions that are happening on the main thread (ie the same thread where you set the MDC value). The rest are probably happening on a different thread. Since there is no value in the MDC for those threads, the filename is null (or empty).

Also, I don't understand what you are hoping to achieve with this line in your configuration:

<variable name="outPutFileFullName" value=""/>

Declaring a variable in the nlog.config file allows you to use that variable name later in on the configuration. A variable doesn't have anything to do, not directly anyway, with referencing an item from the MDC/GDC. See this answer for some examples of how to use variables in your nlog.config:

Most useful NLog configurations

For completeness I will mention that log4net has a LogicalThreadContext (in addition to contexts that correspond to NLog's MDC and GDC). The LogicalThreadContext stores values in the CallContext using LogicalSetData. In this case, all values stored in the LogicalThreadContext will be "flowed" to any child threads or tasks. So, if in thread A you store a value called "Name", and then thread A starts some subthreads (or tasks), the value "Name" will be available in the LogicalThreadContext in each of those subthreads (or tasks).

In your example, if you were using log4net and set the value in the main thread like this:

log4net.LogicalThreadContext.Properties["outputFilename"] = outputFolderFile;

then that value would be available in all of the thread/tasks that are kicked off by the parallel processing.

Here is an article by Jeffrey Richter that describes how CallContext.LogicalSetData works:

http://www.wintellect.com/blogs/jeffreyr/logical-call-context-flowing-data-across-threads-appdomains-and-processes

Nlog not writing all lines into File in Parallel Loop

1 Answers1