serilog / serilog-sinks-opentelemetry

A Serilog OpenTelemetry Protocol (OTLP) sink
Apache License 2.0
117 stars 19 forks source link

Span and Trace Id not populated on log events #114

Closed NicolaiOksen closed 10 months ago

NicolaiOksen commented 10 months ago

I'm currently using Serilog for all logging purposes in our codebase.

Versions

I have the below code to configure serilog for OTEL logging.

logConfiguration
  .Enrich.FromLogContext()
  .Enrich.With(new ThreadIdEnricher())
  .Enrich.With(
      new WebRequestEnricher(
          serviceProvider.GetRequiredService<IHttpContextAccessor>()
      )
  )
  .Enrich.WithExceptionDetails()
  .WriteTo.OpenTelemetry(options =>
  {
      options.Endpoint = otelEndpoint;
      options.Protocol = OtlpProtocol.Grpc;
      options.Headers = new Dictionary<string, string>()
      {
          ["signoz-access-token"] = ingestionKey
      };
      options.ResourceAttributes = new Dictionary<string, object>
      {
          ["service.name"] = cfg.OpenTelemetry.ServiceName,
          ["service.version"] = cfg.OpenTelemetry.ServiceVersion,
          ["service.region"] = cfg.Platform.Region,
          ["service.environment"] = cfg.Platform.Environment
      };
      options.RestrictedToMinimumLevel = GetLevel(cfg.OpenTelemetry.Level);
  })
  .CreateLogger();

However all logs are missing the Span and Trace Id, they are simply empty strings:

{
  "body": "<redacted>",
  "id": "2Xftx5oQG4IDztIN92n9NgEhkH7",
  "timestamp": "2023-11-09T18:32:45.6567739Z",
  "attributes": {
    // Shortened for brevity
  },
  "resources": {
    // Shortened for brevity
    "telemetry_sdk_language": "dotnet",
    "telemetry_sdk_name": "serilog",
    "telemetry_sdk_version": "1.2.0-dev-00247"
  },
  "severity_text": "Information",
  "severity_number": 9,
  "span_id": "",
  "trace_flags": 0,
  "trace_id": ""
}

Could anyone provide some insights as to what might be wrong? Trace and Span Ids are correctly added to traces in the system.

nblumhardt commented 10 months ago

Hi @NicolaiOksen! My bet is that you are using Microsoft.Extensions.Logging's ILogger<T> and haven't added a dependency on the latest preview version of the Serilog.Extensions.Logging package.

There are a few aspects to the new trace and span id propagation used by version 1.2.0 of this sink that need buy-in by other Serilog libraries, and those are all scheduled to ship RTM versions next week alongside .NET 8.

If it sounds like I'm on the right track, you can grab Serilog.Extensions.Logging v7.0.1- or v8.0.0- (previews) from NuGet; note that you'll need it even if your project doesn't have a direct dependency on that package currently (this will go away when RTMed).

You'll also need the latest preview of Serilog.AspNetCore if you're using UseSerilogRequestLogging(), in order to get trace and span ids in with those events.

The other, lower-hassle, option, is to use v1.1.0 of this package for now, since it doesn't depend on any Serilog updates in order to capture and propagate trace and span info.

Hope this helps, keen to hear how you go!

NicolaiOksen commented 10 months ago

Hi @nblumhardt

Thanks for getting back to me - I'll try the suggestions you made.

The other, lower-hassle, option, is to use v1.1.0 of this package for now, since it doesn't depend on any Serilog updates in order to capture and propagate trace and span info.

Hope this helps, keen to hear how you go!

I've already tried 1.1.0 and the span and trace ids are still not propagated. Does that mean the issue is somewhere else?`

nblumhardt commented 10 months ago

Sounds like it's somewhere else - stepping through in the debugger should pinpoint it pretty quickly if that's an option 👍

nblumhardt commented 10 months ago

Hi @NicolaiOksen; any luck so far?

NicolaiOksen commented 10 months ago

Hi @nblumhardt

Thanks for your help - the issue was else where.

We registerede our ILogger instance directly as a Singleton and did not use UseSerilog and AddSerilog.

So going from:

services.AddSingleton(
    f => LogConfigurator.CreateLogger( f.GetRequiredService<LogConfiguration>())
);

to:

Log.Logger = LogConfigurator.CreateLogger(configuration, logConfiguration);
services.AddSerilog(Log.Logger);

fixed the issues I was seeing. Thanks for helping :)

nblumhardt commented 10 months ago

Great! 👍

jochenjonc commented 9 months ago

@nblumhardt I have a similar issue. But my code is based on the ASP.NET example with Two Stage Initialization. And I can't get it working. TraceId and SpanId are nog longer passed to OpenTelemetry (in my case I don't see them anymore in Grafana).

nblumhardt commented 9 months ago

Hi @jochenjonc - posting a copy of the code, including CSPROJ files and other configuration, to a new Stack Overflow post will be the best way to get eyes on it (it'll be a week or two before I'm able to loop back here).

jochenjonc commented 9 months ago

Hi @nblumhardt, while trying to create a sample project I found the issue. I'm still on .NET 7 and in the project I'm referencing Serilog.AspNetCore 7.0.0. When I upgrade the project to .NET 8 and update the reference to Serilog.AspNetCore 8.0.0, the traceIds are back. Another option is to lower the Serlog version to 3.0.1.

It has nothing to do with OpenTelemetry and this repo. This was just the place where I noticed traceids and spanids were missing.