Google-cloud-dotnet: Google.Cloud.Logging.Nlog - Log correlation with traces

[orchowski]

Hi!

Is your feature request related to a problem? Please describe.
I can't correlate stackdriver logs in the tracing panel inside the google console.

I think that's because of the lack of fields like trace, traceId mentioned here https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry

I tried to find in code place where LogEntry is filled and eg. field trace exist, but it's skipped at GoogleStackdriverTarget during object creation.

var logEntry = new LogEntry { Severity = s_levelMap[loggingEvent.Level], Timestamp = ConvertToTimestamp(loggingEvent.TimeStamp), LogName = _logName, Resource = _resource, };
And at other places, algorithm flow fills labels, resources section, and nothing else.

Describe the solution you'd like
Giving the possibility to fill LogEntry fields required for tracing.

If it's possible to then sorry for asking. However, in this case, documentation should be updated.

[jskeet]

Assigning to Amanda who knows more about the relationship between logging and tracing than I do. I strongly suspect this will be tricky to do without just providing some kind of interface (to be implemented by the user) for "here's how I discover the current trace".

[orchowski]

@jskeet or by convention. Do you want to place a trace in the log entry? Then we can look at the JSON payload and assign the same values to it.
trace from payload -> trace inside logEntry

Less complicated i think. Or it'd be better to copy these fields from contextproperties

[amanda-tarafa]

We do this automatically for the Google.Cloud.Diagnostics.AspNetCore* libraries, which do both tracing and logging (not suggesting you change to that by the way). I'd have to take a look at the NLog lib in more detail, to confirm the best way to do this, but I believe that indeed, something as what @jskeet suggests will be necessary, and then we can obtain the trace values provided by that user implemented interface and add them to the LogEntry. I could look into providing an out of the box implementation of that interface for Google Cloud Trace.
I'll take a look this afternoon and confirm.

[jskeet]

@orchowski: I don't think I'd want to tie this to using a JSON payload. It would perhaps be reasonable to have a property that could be specified in NLog entries that would be extracted automatically, but I'm not sure yet.

[amanda-tarafa]

OK, first for associating log entries to traces we are talking about three values: TraceId, SpanId and TraceSampled (false indicates either that the trace was not sampled on the backend or that whether it was sampled or not was unknown at the time of writing the log entry). SpanId and TraceSampled don't need to be set, but if we are going to add the feature, we should support it fully. For the two options discussed above (properties and interface) we would define the type TraceContextForLogEntry that would contain these 3 values.

As for the options some intial rought thoughts (granted I might be missing a lot here, since I'm not very familiar with NLog):

• Have a special property that if detected we extract a TraceContextForLogEntry and set the corresponding values in the LogEntry. This is fairly straightforward both for us to implement and for users to use. Still there a few loose ends:

  • Should that property be "removed" after use so that it's not added to the "normal" set of properties?
  • What if we remove it and there are references to it on layout, implying that the user expects to see it on the "normal" property set or somewhere else.
  • What if we don't remove it, and it's also added as normal property?
  • Should we add a config flag to remove it from normal properties?

  I end up not liking adding "special" properties. This is something that could snowball if similar requests start to come in.

• Have a ITraceContextProvider interface that users can implement and specify the type of their implementation in the config file. The problem here is how to inject this provider into the GoogleStackdriverTarget. And more importantly, how to inject it in a way that this provider can get its own dependencies through DI. Injecting dependencies in NLog is not straightforward and requires user code for configuring the logger, appart from the XML config file.

  • I'm favouring using NLog DI to inject an Microsoft.Extensions.DependencyInjection.IServiceProvider from which we can obtain the ITraceContextProvider implementation that the user specifies in config. We would have to take a dependency on Microsoft.Extensions.DependencyInjection though. (I'm thinking that users can wrap their own DI mechanism on an implementation of IServiceProvider)
  • An alternative is to have the user directly inject the ITraceContextProvider using NLog DI mechanism, but if other similar providers are needed in the future, constructor overload will explode. And we would be pushing solving DI to the user very strongly.

Thoughts welcome.

[snakefoot]

For NLog the expected approach would be the use of Layout-properties on GoogleStackdriverTarget:

```c#
public partial class GoogleStackdriverTarget
{
public Layout Trace { get; set; }
public Layout SpanId { get; set; }
}

private LogEntry BuildLogEntry(LogEventInfo loggingEvent)
{
var logEntry = new LogEntry
{
LogName = _logName,
};

   var trace = RenderLogEvent(Trace, loggingEvent);
   if (!string.IsNullOrEmpty(trace))
          logEntry.Trace = trace;

   var spanId = RenderLogEvent(SpanId, loggingEvent);
   if (!string.IsNullOrEmpty(spanId))
          logEntry.SpanId = spanId;

}
```

The user can then configure the Layout-property to use the wanted layoutrenderer, and the user can also register custom layoutrenderers to capture context.

Maybe create a new NLog specific nuget-package that knows about Google.Cloud.Diagnostics.Common.ContextTracerManager and Google.Cloud.Diagnostics.Common.TraceHeaderContext.

Notice Microsoft DotNet have something called System.Diagnostics.Activity.Current that contains TraceId + SpanId. If Google-Cloud integrated nicely with System.Diagnostics.Activity.Current then NLog.DiagnosticSource might be all you need.

[amanda-tarafa]

@snakefoot thanks for the info. It did feel like I was going down a rabbit hole earlier. I'll reply in more detail tomorrow.

[amanda-tarafa]

@orchowski I might be able to work on this some next week, but I can't be sure right now. If it's not next week, then I won't get to it till next year.

@snakefoot , again, thanks for the info.

Maybe create a new NLog specific nuget-package that knows about Google.Cloud.Diagnostics.Common.ContextTracerManager and Google.Cloud.Diagnostics.Common.TraceHeaderContext.

We probably wound't do that. After all, Google.Cloud.Diagnositcs.* is just one way in which traces can be managed. We even, recently, got a feature request (#5044) to support external traces in the logging component of Google.Cloud.Diagnostics.*.

I've been thinking more about providing some out of the box trace provider for Google Cloud Trace in the NLog lib, and really, we could only (reliably) get the trace context as specified on the headers of the request, but that wouldn't be accurate because more spans could have been created during the request (through Google.Cloud.Diagnostics.* or anything else). So I feel more confortable adding an example showing how to extract the Google Cloud Trace info from headers and configure NLog to include those in the log entry than anything else.

Notice Microsoft DotNet have something called System.Diagnostics.Activity.Current that contains TraceId + SpanId. If Google-Cloud integrated nicely with System.Diagnostics.Activity.Current then NLog.DiagnosticSource might be all you need.

Yep, something that we might look at in the future, but not soon enough to address this FR.

[snakefoot]

@amanda-tarafa get the trace context as specified on the headers of the request

The NLog.Web.AspNetCore-nuget-package contains a layoutrenderer called ${aspnet-request-headers:HeaderNames=MyHeaderName}. Maybe it is just a matter of transforming the contents of the Google-Request-Header ?