[ExtendedLogger] {OriginalFormat} is incorrectly exported by OpenTelemetry

[iliar-turdushev]

Description

If a logger emits the {OriginalFormat} property OpenTelemetry handles it in a special way (see open-telemetry/opentelemetry-dotnet#4334, Changes section):

Our ExtendedLogger does emit the {OriginalFormat} property, but it is not always handled by OpenTelemetry as it is described above. For example, regardless of the value of the IncludeFormattedMessage property OpenTelemetry always exports source generated logs produced by ExtendedLogger as formatted messages, i.e. it replaces the arguments in {OriginalFormat} and exports the resulting value as the LogRecord.Body property.

The correct behavior must be the following:

• If IncludeFormattedMessage=true then LogRecord.Body must contain the formatted message.
• If IncludeFormattedMessage=false then LogRecord.Body must contain the message format, i.e. the value of the {OriginalFormat} property.

This bug affects how log records are exported to the telemetry backend.

The bug is caused by the fact that ExtendedLogger doesn't ensure that the {OriginalFormat} property is the last in the collection of log properties, which is required by OpenTelemetry. Hence, the fix would be to ensure that the property is always returned as the last one.

We need to fix the bug and ensure that the {OriginaFormat} property is handled correctly in the following use cases:

• source-generated logs
• regular logs emitted by methods like LogInformation
• the above two cases must be validated when enrichment, static enrichment, and redaction, are enabled and used, because these features could affect the order of the {OriginalFormat} property in the collection of log properties

Reproduction Steps

Project file:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <LangVersion>13</LangVersion>
    <Nullable>enable</Nullable>
    <TargetFramework>net8.0</TargetFramework>
    <OutputType>Exe</OutputType>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.Extensions.Logging" Version="8.0.1" />
    <PackageReference Include="Microsoft.Extensions.Telemetry" Version="8.10.0" />
    <PackageReference Include="OpenTelemetry.Exporter.Console" Version="1.8.1" />
  </ItemGroup>
</Project>

C# code:

using Microsoft.Extensions.Logging;
using OpenTelemetry.Logs;

internal static class Program
{
    public static void Main()
    {
        using var loggerFactory = LoggerFactory.Create(builder =>
        {
            builder
                .EnableEnrichment()
                .AddOpenTelemetry(loggerOptions =>
                {
                    loggerOptions.IncludeFormattedMessage = false;
                    loggerOptions.AddConsoleExporter();
                });
        });

        var logger = loggerFactory.CreateLogger("Logger");

        logger.TestMessage("Hello", "world");
        logger.LogInformation("LogInformation: {arg1}, {arg2}", "Hello", "world");
    }
}

internal static partial class Log
{
    [LoggerMessage(0, LogLevel.Information, "LoggerMessage: {arg1}, {arg2}")]
    public static partial void TestMessage(this ILogger logger, string arg1, string arg2);
}

Expected behavior

Both log statements must emit a LogRecord that has the message format in the LogRecord.Body property, i.e.

LogRecord.Body = "LoggerMessage: {arg1}, {arg2}"

Actual behavior

When running the sample you'll get the following result:

Note that the first message produced by the source generated log statement has the formatted message in the LogRecord.Body property, while the second message produced by the LogInformation method has the message format in the LogRecord.Body.

The second message has the correct value in the LogRecord.Body because the LogInformation method ensures that the {OriginalFormat} property is the last in the collection. But if you enable enrichment then the second log statement will also have incorrect LogRecord.Body value.

Regression?

No response

Known Workarounds

No response

Configuration

No response

Other information

No response

[dariusclay]

Thank you @iliar-turdushev for investigating this!