feat: Make ambient Activity tracing opt-in and enhance mapping config

[hangy]

This pull request introduces significant improvements to the documentation and enrichers for Serilog's Application Insights sink, clarifying configuration, enhancing support for distributed tracing, and adding new enrichment capabilities. The most important changes are grouped below:

Documentation and Configuration Improvements:

• The README.md has been extensively updated to clarify recommended configuration patterns, add installation instructions, and explain the precedence of operation ID sources and integration with distributed tracing libraries such as SerilogTracing. It also documents the new enrichers, upgrading guidance for 5.0, and details about operation-related properties mapping.

Distributed Tracing and Enrichment:

• Added two new enrichers: ActivityOperationNameEnricher and ActivityBaggageEnricher, which can be enabled via new extension methods (WithOperationName, WithBaggage) on LoggerEnrichmentConfiguration to automatically copy tracing context from the current Activity to log events.
• Introduced a new extension class LoggerEnrichmentConfigurationExtensions to provide these enrichment methods for seamless integration.

API and Code Quality Improvements:

• Refactored the extension methods in LoggerConfigurationApplicationInsightsExtensions to use the overload that accepts a TelemetryClient directly, simplifying the API and avoiding redundant sink construction.

These changes collectively modernize the sink's documentation, improve support for distributed tracing scenarios, and make it easier for users to configure and enrich telemetry data.

[nblumhardt]

Thanks for taking a look!

I think this could work, but only if an enricher (ILogEventEnricher) is used to attach the OperationName property from Activity.Current - nothing else will currently set OperationName.

An enricher could be avoided by setting the operation name in the sink's Emit(LogEvent) method using ConditionalWeakTable, but this would require internally wrapping Serilog's batched sink implementation via LoggerSinkConfiguration.Wrap() so that the Emit() call is the one that happens on the application thread at the point the event is created, not the asynchronous/background thread EmitBatch..() methods.

[hangy]

I think this could work, but only if an enricher (ILogEventEnricher) is used to attach the OperationName property from Activity.Current - nothing else will currently set OperationName.

An enricher could be avoided by setting the operation name in the sink's Emit(LogEvent) method using ConditionalWeakTable, but this would require internally wrapping Serilog's batched sink implementation via LoggerSinkConfiguration.Wrap() so that the Emit() call is the one that happens on the application thread at the point the event is created, not the asynchronous/background thread EmitBatch..() methods.

You're right. I'll take a look at it. I guess there are several camps when using this Sink. Personally, I don't really need the OperationName as we integrate this Sink with Traces being sent through the AppInsights SDK as well as Logs via Serilog. Will see how to best add the OperationName without disruping other usage scenarios.

[nblumhardt]

Looking at #239 and the complexity involved here, I wonder if we're better off putting the new behavior added in 4.1 behind an opt-in configuration option? Currently it seems like fixing this reliably will take a while, so having the sink ignore LogEvent.TraceId etc. by default could provide a way to keep the existing ecosystem functioning while the dust settles?

[hangy]

Looking at #239 and the complexity involved here, I wonder if we're better off putting the new behavior added in 4.1 behind an opt-in configuration option? Currently it seems like fixing this reliably will take a while, so having the sink ignore LogEvent.TraceId etc. by default could provide a way to keep the existing ecosystem functioning while the dust settles?

Maybe. I want to spend some more time today to try to figure this out.

So far, I've found out that the baggage items and potentially the operation name being present in traces in v4.0.0 of this sink may just have been a lucky coincidence:

If I don't set/change the telemetry.Context.Operation.Id like

serilog-sinks-applicationinsights/src/Serilog.Sinks.ApplicationInsights/Sinks/ApplicationInsights/TelemetryConverters/TelemetryConverterBase.cs

Line 151 in 2b3e6cd

telemetry.Context.Operation.Id = traceId.ToHexString();

then something happens automatically.

serilog-sinks-applicationinsights/src/Serilog.Sinks.ApplicationInsights/Sinks/ApplicationInsights/ApplicationInsightsSink.cs

Line 139 in 2b3e6cd

_telemetryClient?.Track(telemetry);

Before this line, the baggage of my manually created Activity is not present in the TraceTelemetry.Properties, and after the call to Track, the property magically appears. Same for the operation name in the nested OperationContext instance.

If I modify the call to Track to have it's own Activity, ie.

using Activity disruptor = new("DisruptorActivity");
{
    disruptor.AddBaggage("TakenFromAmbient", "true");
    disruptor.Start();
    _telemetryClient?.Track(telemetry);
}

If I don't set telemetry.Context.Operation.Id to the logEvent.TraceId, then the log/Trace in Application Insights contains the TakenFromAmbient custom property. If I do set it, however, the log message does not contain the TakenFromAmbient custom property.
=> Apparently, TelemetryClient.Track fills several properties of the TraceTelemetry based on the ambient Activity.Current instance. If Serilog asynchronously (or in another thread/different AsyncLocal context) calls the ApplicationInsightsSink.Emit method, and the ambient Activity might be a different one than at the time the LogEvent was created, the OperationName, TraceId, and Baggage could be incorrect.

[hangy]

1. TelemetryConfiguration https://github.com/microsoft/ApplicationInsights-dotnet/blob/2.23.0/BASE/src/Microsoft.ApplicationInsights/Extensibility/Implementation/TelemetryConfigurationFactory.cs#L67 is always initialized with an OperationCorrelationTelemetryInitializer instance.
2. OperationCorrelationTelemetryInitializer adds OperationName, Baggage, and more, if (string.IsNullOrEmpty(itemOperationContext.Id)): https://github.com/microsoft/ApplicationInsights-dotnet/blob/2.23.0/BASE/src/Microsoft.ApplicationInsights/Extensibility/OperationCorrelationTelemetryInitializer.cs#L72-L87 - all from Activity.Current

@nblumhardt I suggest to

• Deprecate v4.1.0 as it obviously contains unintended breaking changes.
• Revert 4c33dac as the main cause of the breaking change, and release a v4.1.1 with this fix
• To avoid issues caused by this implicit behaviour of the TelemetryClient, based on this PR:
  • Make adding the OperationName and Baggage explicit by providing custom/optional enrichers that add them to the log event's properties
  • Ensure that some telemetryItem.Context.Operation.Id is always set before telemetryClient.Trace is called to ensure that the AppInsights SDK doesn't get potentially incorrect values from Activity.Current.
  • Release this as a new v5 of the sink to document this breaking behaviour

What's your opinion on this approach?

[nblumhardt]

That sounds good, @hangy, thanks for looking into it!

@magnusn @ErikPilsits-RJW we'd need to validate that this fixes the issues you raised before shipping it; are you in a position to try out a -dev-* build once one is available? If so, please let us know so we can keep you in the loop. Thanks!

[ErikPilsits-RJW]

Yes I am able to test a dev build. I'm a little unclear on if I need to make any other changes based on:

• Make adding the OperationName and Baggage explicit by providing custom/optional enrichers that add them to the log event's properties

But just let me know what config changes I might need to make, if any. I guess that depends if you're asking me to test the reverted v4.1.1 or the new v5 also. But either way, let me know what you need.

[hangy]

That sounds good, @hangy, thanks for looking into it!

I prepared two branches based on tag v4.1.0 instead of dev so it could actually be a patch release:

• https://github.com/hangy/serilog-sinks-applicationinsights/commits/4.x/ if you want to full revert 4c33dac
• https://github.com/hangy/serilog-sinks-applicationinsights/commits/4.x-with-package-upgrades/ if you just want the functional changes reverted, but want to keep the dependency updates (probably the better version)

@magnusn @ErikPilsits-RJW we'd need to validate that this fixes the issues you raised before shipping it; are you in a position to try out a -dev-* build once one is available? If so, please let us know so we can keep you in the loop. Thanks!

Sorry for causing these issues. It was totally unintended, and I hadn't checked baggage/operation name, as it wasn't one of my uses cases (and no tests existed for this implicit behaviour).

Yes I am able to test a dev build. I'm a little unclear on if I need to make any other changes based on:

* Make adding the OperationName and Baggage explicit by providing custom/optional enrichers that add them to the log event's properties

But just let me know what config changes I might need to make, if any. I guess that depends if you're asking me to test the reverted v4.1.1 or the new v5 also. But either way, let me know what you need.

Thank you! A patched v4.1.1 or v4.2.0 should work the same as v4.0.0, except it won't manually set the TraceId/SpanId from the LogEvent.
For a potential v5, I'll try and update the docs to be very explicit on what needs to be done for this breaking change. Theoretically, it could be a enricher, so the configuration might look something like:

var log = new LoggerConfiguration()
    .WriteTo.ApplicationInsights(TelemetryConfiguration.Active, TelemetryConverter.Traces)
    .Enrich.WithActivityBaggage() // To copy `Activity.Baggage` to log event properties
    .Enrich.WithActivityOperatioName() // To copy the `OperationName` tag from `Activity.Tags` to log event properties
    .CreateLogger();

[ErikPilsits-RJW]

That sounds good, thank you.

So if I'm reading this correctly, you're implying there's a risk here of getting Baggage that doesn't explicitly belong to the LogEvent, because it comes from the ambient Activity at the time the LogEvent is written, and that happens asynchronously? If I've understood that correctly, is this the case currently with v4?

Our use case for the Baggage is to attach telemetry information to log events that occur downstream in our other API layers. This allows us to correlate business data more easily directly from those app insights log entries. It also attaches that data to our Exception telemetry.

I'm not sure the mechanism here exactly. Is this not coming through Serilog?

Example Exception telemetry

[hangy]

So if I'm reading this correctly, you're implying there's a risk here of getting Baggage that doesn't explicitly belong to the LogEvent, because it comes from the ambient Activity at the time the LogEvent is written, and that happens asynchronously? If I've understood that correctly, is this the case currently with v4?

I don't know enough about the inner workings of Serilog to answer this with absolute certainty. In my local tests with v4.1.0, the ambient Activity.Current was always correct, but I wouldn't rule out oddities when it comes to multi-threading. Maybe it's only an issue one uses a sink like PeriodicBatchingSink as a wrapper around ApplicationInsightsSink.

I'm not sure the mechanism here exactly. Is this not coming through Serilog?

Not directly. Prior to this PR, Serilog did not contain any code that explicitly copied the Activity.Baggage items to the ITelemetry item that's sent to Application Insights. According to the code if dug up the Application Insights SDK itself copies the data to the ITelemety, but only if the Operation.Id is not set.

[magnusn]

@hangy

I tested the https://github.com/hangy/serilog-sinks-applicationinsights/commits/4.x-with-package-upgrades/ branch now and using it the operation name is back and it works as it did previously.

Thanks for your work!