This post is part 1 of a series on .NET distributed tracing and OpenTelemetry, showing W3C Trace Context distributed tracing is already built in to the default web client, server, and other operations in modern .NET systems.

You can see the support for distributed tracing with a basic example, by configuring your logging to display the correlation identifier. Many logging systems, such as Elasticsearch, display correlation by default. The identifiers can also be passed across messaging, such as Azure Message Bus.

Logging has always been a useful way to understand what is happening within a system and for troubleshooting. However, modern systems are very complex, with multiple layers and tiers, including third party systems.

Trying to understand what has happened when a back end service log reports an error, and then correlating that to various messages and front end actions that triggered it requires some kind of correlation identifier.

This problem has existed ever since we have had commercial websites, for over 20 years of my career, with various custom solutions.

Finally, in 2020, a standard was created for the format of the correlation identifier, and how to pass the values: W3C Trace Context. In a very short amount of time all major technology providers have implemented solutions.

The examples below show how this is already implemented in modern dotnet.

Built in distributed tracing

These example are also available in Github: https://github.com/sgryphon/dotnet-distributed-tracing-examples

One of the simplest examples possible for distributed tracing is with two .NET components: a web application, which then calls a back end service. Both the web app and service output logging, with correlated trace IDs.

Diagram with three components: Browser, Demo.WebApp, and Demo.Service

Create a back end Demo.Service and a front end Demo.WebApp, using the .NET weather forecast sample application.

dotnet new webap --output Demo.Service
dotnet new webap --output Demo.WebApp

Instead of having the web app API return the data directly, use the standard HttpClient to call the back end service, registering the built in system factory in Startup.cs to ensure the correct lifecycle is applied.

public void ConfigureServices(IServiceCollection services)
{
  ...
  services.AddHttpClient();
}

Modify WeatherForecastController.cs in Demo.WebApp app to inject the HttpClient and ILogger<T>, and then using them in the Get handler.

private readonly System.Net.Http.HttpClient _httpClient;
private readonly ILogger<WeatherForecastController> _logger;

public WeatherForecastController(ILogger<WeatherForecastController> logger, 
  System.Net.Http.HttpClient httpClient)
{
  _logger = logger;
  _httpClient = httpClient;
}

[HttpGet]
public Task<string> Get(System.Threading.CancellationToken cancellationToken)
{
  _logger.LogWarning(4001, "WebApp API weather forecast request forwarded");
  return _httpClient.GetStringAsync("https://localhost:44301/WeatherForecast", cancellationToken);
}

Also add a logging statement to WeatherForecastController.cs in the back end Demo.Service:

public IEnumerable<WeatherForecast> Get()
{
  _logger.LogWarning(4002, "TRACING DEMO: Back end service weather forecast requested");
  ...
}

At this point, you have a standard .NET application, with two server components: a web app, which then calls a back end service. They have standard .NET ILogger<T> logging, but nothing extra.

If you run both components now, you won't see the distributed tracing, but in the latest version of .NET it is happening behind the scenes, built into HttpClient and ASP.NET.

Showing the distributed trace identifiers

To see the distributed traces, it is a simple matter to add configuration settings to output scopes.

Add this section to appSettings.Development.json, in both projects.

{
  "Logging": {
    "Console": {
      "FormatterName": "simple",
      "FormatterOptions": {
        "IncludeScopes": true
      }
    },
    ...
  }
}

Then run both applications.

Distributed tracing correlation is built in to the default HttpClient and web server, and passed between the tiers to be included in log messages. All you need to do is enable the output in the logger configuration (click on the image to expand).

Example console output showing basic logs with correlated trace identifiers

Elasticsearch + Kibana example

Distributed trace correlation is also supported out of the box by many logging providers.

For example, you can run a local Elasticsearch service to send logs to from multiple services, so they can be viewed together.

Using the same components as the basic example above, a web application which then calls a back end service, you can configure them both to send logs to Elasticsearch:

Diagram with two components, Demo.WebApp and Demo.Service, connected to Elasticsearch and then Kibana

To configure this add the Elasticsearch.Extensions.Logging (https://github.com/elastic/ecs-dotnet/blob/main/src/Elasticsearch.Extensions.Logging/ReadMe.md) logging provider from Nuget:

dotnet add Demo.WebApp package Elasticsearch.Extensions.Logging --version 1.6.0-alpha1

And then configure it in Program.cs.

using Elasticsearch.Extensions.Logging;
...
Host.CreateDefaultBuilder(args)
  .ConfigureLogging((hostContext, loggingBuilder) =>
  {
    loggingBuilder.AddElasticsearch();
  })

You can run a local instance of Elasticsearch and Kibana, e.g. via Docker, to view the combined logs and filter on specific traces.

Example Kibana log output

For more details, including a docker compose file to run the services, see the Elasticsearch example in GitHub.

Azure message bus example

You can also pass distributed tracing identifiers across a message bus, such as Azure Service Bus. This extends the basic example above, adding an Azure Service Bus queue, with the web app writing to the queue, and a worker service listening to it.

The component architecture looks like this:

Diagram with multiple components including Azure Service Bus

Although the Azure message bus documentation talks about Service Bus calls done by your service are automatically tracked and correlated, and does provide tracing instrumentation points, the tracing is only automatic if you are using a tracing provider, such as Application Insights or OpenTelemetry.

If you do not have a tracing provider, then traces are not directly correlated (and activities aren't even used if there is no DiagnosticsListener attached).

For manual correlation, the Diagnostic-Id application property is automatically set when sending messages with the traceparent details of the source activity, so you only need to configure the receiving side to manually start an activity span.

Refer to the Message Bus example on GitHub for full details. You need to:

  • Create a message bus and queue in Azure to use (an Azure Service Bus deployment script is provided).
  • Configure Azure message bus in the web app project and send a demo message.
  • Create a new console Worker app and configure it with basic code to receive the demo message.

At this point, with basic message receiving code the trace correlation identifier is sent automatically (it can be seen when debugging), but not handled at the receiving end (in the worker), and you won't see correlated logs.

Creating a manual activity span

To manually create an activity span, add the following to the beginning of the message processing code to start an Activity (span in W3C terminology) set with the provided parent.

serviceBusProcessor.ProcessMessageAsync += args =>
{
  using var activity = new System.Diagnostics.Activity(ServiceBusProcessor.ProcessMessage);
  if (args.Message.ApplicationProperties.TryGetValue("Diagnostic-Id", out var objectId) &&
    objectId is string traceparent)
  {
    activity.SetParentId(traceparent);
  }
  activity.Start();

  _logger.LogWarning(4003, "Message received: {MessageBody}", args.Message.Body);
  return Task.CompletedTask;
};

With all three tiers logging to Elasticsearch, you can see the correlated results by Trace ID in Kibana.

Example Kibana output wth correlated identifiers

Next steps

The examples above show how distributed tracing correlation is already built in to modern .NET applications, fully supported in the HttpClient and server, and partially supported in Azure message bus.

The next step is not just log correlation, using the W3C trace identifier, but full instrumentation of traces, metrics, and logs via OpenTelemetry, which has support integrated into the .NET System.Diagnostics library.

OpenTelemetry logo

OpenTelemetry is covered in the next article in this series: .NET Distributed Tracing 2: Instrumenting with OpenTelemetry

Thumbnail picture from: https://pixabay.com/illustrations/pulse-trace-healthcare-medicine-163708/