Connecting OpenTelemetry traces and logs

This sample shows how to configure an NServiceBus endpoint to link OpenTelemetry traces and logs together.

Configuration

First, configure OpenTelemetry to capture NServiceBus traces:

builder.ConfigureServices(services =>
{
    services.AddOpenTelemetry()
    .ConfigureResource(resourceBuilder => resourceBuilder.AddService(EndpointName))
    .WithTracing(builder =>
    {
        builder.AddSource("NServiceBus.*");
        builder.AddConsoleExporter();
    });
});

In this example, all telemetry is sent to a ConsoleExporter, but any OpenTelemetry-compliant exporter will work.

Next, connect the logs emitted by the application to the traces as follows:

builder.ConfigureLogging((ctx, logging) =>
{
    logging.AddConfiguration(ctx.Configuration.GetSection("Logging"));

    logging.AddOpenTelemetry(loggingOptions =>
    {
        loggingOptions.IncludeFormattedMessage = true;
        loggingOptions.IncludeScopes = true;
        loggingOptions.ParseStateValues = true;
        loggingOptions.AddConsoleExporter();
    });

    logging.AddConsole();
});

This will apply the OpenTelemetry logging format to all the logs. More importantly, it will correlate all logs to the active traces. This means that each log statement will include a TraceId and SpanId as part of the log entry.

Lastly, the NServiceBus endpoint must enable the OpenTelemetry instrumentation:

builder.UseNServiceBus(ctx =>
{
    var endpointConfiguration = new EndpointConfiguration(EndpointName);
    endpointConfiguration.UseSerialization<SystemJsonSerializer>();
    endpointConfiguration.UseTransport(new LearningTransport());

    endpointConfiguration.EnableOpenTelemetry();

    return endpointConfiguration;
});

Running the sample

When running the sample, the following log statement from the message handler:

logger.LogInformation("Received message #{Number}", message.Number);

will lead to the following output:

 info: MyMessageHandler[0]
 Received message #54
 LogRecord.Timestamp:               2022-06-28T09:02:34.5342602Z
 LogRecord.TraceId:                 964b320925ab08cd2134c02d0abe920d
 LogRecord.SpanId:                  066fce94c5438add
 LogRecord.TraceFlags:              Recorded
 LogRecord.CategoryName:            MyMessageHandler
 LogRecord.LogLevel:                Information
 LogRecord.FormattedMessage:        Received message #54
 LogRecord.StateValues (Key:Value):
 {OriginalFormat}: Received message #54
 LogRecord.ScopeValues (Key:Value):
 [Scope.0]:SpanId: 066fce94c5438add
 [Scope.0]:TraceId: 964b320925ab08cd2134c02d0abe920d
 [Scope.0]:ParentId: e595cc6a4d9b0768

The console will also show information for the captured traces:

Activity.TraceId:          964b320925ab08cd2134c02d0abe920d
Activity.SpanId:           066fce94c5438add
Activity.TraceFlags:           Recorded
Activity.ParentSpanId:    eb999a0dadc477ea
Activity.ActivitySourceName: NServiceBus.Core
Activity.DisplayName: MyMessageHandler
Activity.Kind:        Internal
Activity.StartTime:   2022-06-28T09:02:34.5322602Z
Activity.Duration:    00:00:00.0017675
Activity.Tags:
    nservicebus.handler.handler_type: MyMessageHandler
StatusCode : Ok
Resource associated with Activity:
    service.name: Samples.Hosting.GenericHost
    service.instance.id: 93d66e53-7537-4e21-99f9-e62b579b5fa3