Operation name is missing in traces during message handling after update from version 4.0.0 to 4.1.0

[magnusn]

Description
After upgrading from version 4.0.0 to version 4.1.0 of Serilog.Sinks.ApplicationInsights we do not get Operation name in Application Insights for traces that are written during handling of Rebus messages.

Unsure if this is a bug or an intended change in behavior. I have verified that it is the NuGet package Serilog.Sinks.ApplicationInsights causing the problem by installing version 4.0.0 instead and then it works as before.

Reproduction
Here is the code we use for configuring the logging.

    private static void ConfigureLogging(IUnityContainer container, IConfiguration configuration)
    {
        var loggerConfiguration = BasicLoggerConfiguration();

        var appInsightsConnectionString = configuration.GetConfigurationSettingValue("ApplicationInsights.ConnectionString");
        if (!string.IsNullOrEmpty(appInsightsConnectionString))
        {
            loggerConfiguration = loggerConfiguration.WriteTo.Conditional(
                e => e.Level >= LogEventLevel.Information,
                c => c.ApplicationInsights(container.Resolve<TelemetryConfiguration>(), TelemetryConverter.Traces, LogEventLevel.Information));
        }

        Log.Logger = loggerConfiguration
            .WriteTo.Console()
            .CreateLogger();

        Trace.Listeners.Add(new SerilogTraceListener());
    }

    private static LoggerConfiguration BasicLoggerConfiguration()
    {
        var config = new LoggerConfiguration()
            .Enrich.With<SourceInformationEnricher>()
#if DEBUG
            .MinimumLevel.Debug()
#else
            .MinimumLevel.Information()
#endif
            .MinimumLevel.Override("Rebus.Pipeline.Receive.DispatchIncomingMessageStep", LogEventLevel.Debug)
            .MinimumLevel.Override("Rebus.Pipeline.Send.SendOutgoingMessageStep", LogEventLevel.Debug);

        return config;
    }

Then we as an incoming step for Rebus creates a RequestTelemetry

var requestTelemetry = new RequestTelemetry
{
    Name = $"Dequeue {this.endpointName} | {headers[Headers.Type]}"
};

If we then log a trace inside a message that is handled, we get this problem.

public async Task Handle(SomeMessage message)
{
    Log.Information("Some test log");
}

Expected behavior
Expected Operation name to still have the value set.

Relevant package, tooling and runtime versions
We run the application as a WebJob instance in Azure. It is using .NET Core and .NET 9.

Relevant NuGet package versions (hope I included what is relevant, otherwise just ask)

• Microsoft.ApplicationInsights, 2.23.0
• Microsoft.Azure.WebJobs, 3.0.43
• Rebus, 8.9.0
• Rebus.Serilog, 8.1.0
• Serilog, 4.3.0
• Serilog.AspNetCore, 9.0.0
• Serilog.Sinks.ApplicationInsights, 4.1.0
• Serilog.Sinks.Console, 6.1.1
• Serilog.Sinks.Debug, 3.0.0
• SerilogTraceListener, 3.2.0

Additional context
The start of the message handling is logged as a request telemetry and it has the Operation name set correctly as before. It is trace logging done as part of the handling of the message, as for instance Log.Information("Some test log");, that is missing the Operation name.

[nblumhardt]

Thanks for the report, @magnusn 👍

My best guess is that the problem is in this change: https://github.com/serilog-contrib/serilog-sinks-applicationinsights/pull/233/files, since it's the only one to touch operation details, aside from the SDK update (which should also be considered a possible cause).

Looking over it again, I am suspicious of the assignment of ParentId to the current span id in TelemetryConverterBase line 154.

If you're able to grab the source, and possibly comment out or tweak those lines to confirm, a fix/patch PR would be welcome. I'm nominally the maintainer of this package but I don't use Application Insights personally.

[magnusn]

Yes the problem is in that part.

I have been able to determine that the problem is because of the assignment of Id to the current trace id in TelemetryConverterBase line 151.

When debugging I can see that in my example none of the operation properties are set when coming into the code in TelemetryConverterBase. Looking at the code in Microsoft.ApplicationInsights and specifically OperationCorrelationTelemetryInitializer I can see that the code sets Id, ParentId and Name if Id is not already set (as well as some other stuff).

So in my case the current code overrides the code in Microsoft.ApplicationInsights, and thus I do not get Name set.

But I guess those who requested/implemented this got some value from the changes and there is some case where the standard code in Microsoft.ApplicationInsights is not enough.

To solve it, it seems like the following code could be added

var currentActivity = Activity.Current;
if (currentActivity != null)
{
    telemetry.Context.Operation.Name = currentActivity.Tags.FirstOrDefault(tag => tag.Key == "OperationName").Value;
}

Do you think that is how we should proceed? I'm quite a bit unsure here what is the proper way of handling it, since there are a lot I don't understand regarding how this is meant to work.

[nblumhardt]

Thanks for digging into it! I'm not 100% across the motivating scenario for the earlier change - @hangy any thoughts?

I don't think retrieving the name from the current activity would be reliably correct at this point.

[hangy]

I wonder if I made a mistake mapping the fields from https://github.com/serilog/serilog/blob/7f3a5bfec73dba1c3b29780b85a53b0fe2f7c52b/src/Serilog/Events/LogEvent.cs#L105. I'll see if I can fix this.

To solve it, it seems like the following code could be added

var currentActivity = Activity.Current;
if (currentActivity != null)
{
    telemetry.Context.Operation.Name = currentActivity.Tags.FirstOrDefault(tag => tag.Key == "OperationName").Value;
}

That won't work reliably because of Serilog collecting the data before, and submitting the log data later. The Activity.Current can be totally different to the one that was current when the log event was created. It may be possible to use an enricher, though.

[hangy]

@magnusn This should be fixed in v5.0.0-dev-02322. See https://github.com/serilog-contrib/serilog-sinks-applicationinsights/tree/27d28735d3d380a8a698f79f6f406bc2b33861af?tab=readme-ov-file#enriching-from-activity-explicit-opt-in for the opt-in

[magnusn]

@magnusn This should be fixed in v5.0.0-dev-02322. See https://github.com/serilog-contrib/serilog-sinks-applicationinsights/tree/27d28735d3d380a8a698f79f6f406bc2b33861af?tab=readme-ov-file#enriching-from-activity-explicit-opt-in for the opt-in

@hangy I have not had time to test it until now.

Now I tested it on the released 5.0.0 version.

Changed configuration to

Log.Logger = loggerConfiguration
    .Enrich.WithActivityDetails(includeOperationName: true, includeBaggage: true)
    .WriteTo.Console()
    .CreateLogger();

The Operation name is now set as Microsoft.ApplicationInsights.OperationContext so seems more like it is fetching the name of the class or something than the actual name of the operation. 🤔

[nblumhardt]

@magnusn thanks for taking a look. The code that adds operation name enrichment looks pretty straightforward to me:

https://github.com/serilog-contrib/serilog-sinks-applicationinsights/blob/dev/src/Serilog.Sinks.ApplicationInsights/Sinks/ApplicationInsights/Enrichers/ActivityDetailsEnricher.cs#L48

but I'm not really familiar with the App Insights SDK so there may be some crossover between Activity.OperationName and the type you mention? Sounds like it needs some debugging 👍

I'm not an App Insights user (just caretaker over here, since no one from the App Insights world was able to step in as maintainer when we moved provider-specific sinks out of Serilog), so help from anyone following along would be appreciated. Cheers!

[magnusn]

@nblumhardt @hangy

When asking AI about this it says that

Activity.OperationName represents the technical span type, not the logical or business operation.

When using Application Insights, this value is often set to a constant such as:

Microsoft.ApplicationInsights.OperationContext

This name is created by the Application Insights SDK as an internal wrapper activity and is intended for span hierarchy, correlation, and sampling, not for semantic identification.

The actual operation name used by Application Insights (the one shown in the Azure Portal and used for grouping) is stored in Activity tags (e.g. OperationName, ai.operation.name), not in Activity.OperationName.

Using Activity.OperationName in this context therefore produces:

• Low‑value, technical names
• Incorrect or misleading log data
• Loss of the logical operation identity

To capture the meaningful operation name, it should be read from Activity.TagObjects / Activity.Tags (with DisplayName as an optional fallback).

Some resource also pointing in this direction: https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.activity.operationname?view=net-10.0

When debugging I changed the code accordingly and then it works as before:

private void EnrichOperationName(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, Activity activity)
{
    if (!_includeOperationName)
    {
        return;
    }

    string operationName = null;

    if (activity.TagObjects is not null)
    {
        operationName = activity.TagObjects
            .FirstOrDefault(t => t.Key == TelemetryConverterBase.OperationNameProperty)
            .Value as string;
    }

    operationName ??= activity.Tags
        .FirstOrDefault(t => t.Key == TelemetryConverterBase.OperationNameProperty)
        .Value;

    if (!string.IsNullOrEmpty(operationName))
    {
        LogEventProperty operationNameProperty = propertyFactory.CreateProperty(TelemetryConverterBase.OperationNameProperty, operationName);
        logEvent.AddPropertyIfAbsent(operationNameProperty);
    }
}