Nlog: Trace.CorrelationManager.ActivityId is lost when target is wrapped into AsyncTargetWrapper

[kuznero]

ActivityId is thread local and thus getting lost when Target.Write is invoked on another thread. It would be great to pass its value through with each message that is in the buffer as each could have been coming from different thread and reset ActivityId before calling Target.Write for each message.

Current implementation is based on sending batches of log events into specific targets to perform batch writes (e.g. FileWriter). Thus it is not possible to pass correlation ID with thread local Trace.CorrelationManager.ActivityId without modifying specific targets. And even though it would have been possible granted all the codebase is available, it is not a good approach as one would need to remember doing this in a new target implementation for each individual event in Write method.

Thus, the workaround for now is to hack own logger layer to create LogEvent that also contains correlation ID property, that is then used with a custom LayoutRenderer or directly from a custom Target.

[304NotModified]

Is this an issue by using the MDC and not the MDLC?

[kuznero]

I don't think MDC will help here since when moving to a different thread we lose all the thread local information whether that is in Trace.CorrelationManager.ActivityId or anywhere else. Basically, I think it is not possible to nicely befriend AsyncWrapperTarget with the way NLog decided to propagate correlation information. Clients will have to do something about it.

But I would be happy to be proven wrong on that one.

[snakefoot]

@kuznero If Trace.CorrelationManager.ActivityId is very important to have as LogEvent-property, would it not be easier to make Log-Extension-Methods that captures this information and then forwards it to the normal NLog-Log-Methods ?

[snakefoot]

@kuznero Even better alternative is that you just use the activityid-layout-renderer. It is marked to be rendered on the main-thread with the correct context.

[kuznero]

Thanks @snakefoot, are you sure that ${activityid} is rendered on the main thread (actually in has to be rendered on a thread where ActivityId was set to get it properly working) with even with AsyncTargetWrapper? Simply by looking at the signature of Write that accepts either LogEventInfo or list of it, I could assume that layout is rendered on writing thread (not the same when _logger.Info for example is called, but the one that is performing the write operation itself).

With regards to passing it through with LogEventInfo - this is exactly what I meant as a workaround in the original post about adding it it as a property (either in extension method or somehow differently - it does not matter).

[snakefoot]

@kuznero Yes ${activityid} will be rendered on the thread that calls the Log-method.

[kuznero]

ok, that makes sense indeed - you need to properly resolve thread ID and information alike. Then the question left is - is it possible to use value rendered as ${activityid} from withing Write method of a custom target that users creating?

[snakefoot]

is it possible to use value rendered as ${activityid} from withing Write method of a custom target

@kuznero Well if the custom-target has a Layout-property, that is configured to contain ${activityid}, then LogEventInfo will cache the rendering-result of the Layout, so it can be accessed in the Write-method of the custom-target.

[304NotModified]

@kuznero Well if the custom-target has a Layout-property, that is configured to contain ${activityid}, then LogEventInfo will cache the rendering-result of the Layout, so it can be accessed in the Write-method of the custom-target.

Yes indeed, something like this:

```c#

class MyTarget : Target
{
public MyTarget()
{
Activityid = new TraceActivityIdLayoutRenderer () // or use "${activityid}";
}

 // should be public and non-static, see PropertyHelper.GetAllReadableProperties
// this will be precalculated on the main thread, because TraceActivityIdLayoutRenderer  isn't [threadagnostic]
 public Layout Activityid {get;set;}

 protected override void Write(LogEventInfo logEvent){
    string activityId = this.Activityid.Render(logEvent);

 }

}
```

[kuznero]

@304NotModified Excellent! Thanks for example! This is exactly what I was after.