Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[LogProperties] Generated Code Incorrectly Calls ToString() on Nullable-Typed Properties (e.g. DateTime?) #5411

Closed
rwoll opened this issue Sep 9, 2024 · 2 comments · Fixed by #5416
Assignees
Labels
area-compliance bug This issue describes a behavior which is not expected - a bug.

Comments

@rwoll
Copy link
Contributor

rwoll commented Sep 9, 2024

Description

When using the [LogProperties] on an object with nullable-typed properties (e.g. DateTime?), the nullable-typed properties are being forced to string before being added to the state.TagArray while their non-nullable type (DateTime) remains DateTime-typed in the TagArray.

Reproduction Steps

Given the following user-written code:

using Microsoft.Extensions.Logging;

public partial class MyLogger
{
  [LoggerMessage(
    EventId = 1,
    Level = LogLevel.Information,
    Message = "Event triggered!"
  )]
  public static partial void MyLogMessage(ILogger logger, [LogProperties] MyEvent myEvent);

  public class MyEvent
  {
    public DateTime TimeStamp { get; set; }
    public DateTime? TimeStampNullable { get; set; }
  }
}

and csproj:

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net8.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
    <EmitCompilerGeneratedFiles>true</EmitCompilerGeneratedFiles>
    <CompilerGeneratedFilesOutputPath>Generated</CompilerGeneratedFilesOutputPath>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="Microsoft.Extensions.Logging.Abstractions" Version="8.0.1" />
    <PackageReference Include="Microsoft.Extensions.Telemetry.Abstractions" Version="8.9.0" />
  </ItemGroup>
</Project>

Expected behavior

Both myEvent.TimeStamp and myEvent.TimeStampNullable get added to the state.TagArray as DateTimes in the auto-generated logging code.

Actual behavior

In the autogenerated code, myEvent.TimeStamp field gets added to the TagArray as a DateTime (same type as it was in the event), but myEvent.TimeStampNullable is added to the TagArray as a string:

        state.TagArray[2] = new("myEvent.TimeStamp", myEvent?.TimeStamp);
        state.TagArray[1] = new("myEvent.TimeStampNullable", myEvent?.TimeStampNullable?.ToString()); // <--- LINE WITH BUG

Complete generated code:

// <auto-generated/>
#nullable enable
#pragma warning disable CS1591 // Compensate for https://github.com/dotnet/roslyn/issues/54103
partial class MyLogger
{
    /// <summary>
    /// Logs "Event triggered!" at "Information" level.
    /// </summary>
    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "8.9.0.0")]
    public static partial void MyLogMessage(global::Microsoft.Extensions.Logging.ILogger logger, global::MyLogger.MyEvent myEvent)
    {
        if (!logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
        {
            return;
        }

        var state = global::Microsoft.Extensions.Logging.LoggerMessageHelper.ThreadLocalState;

        _ = state.ReserveTagSpace(3);
        state.TagArray[2] = new("myEvent.TimeStamp", myEvent?.TimeStamp);
        state.TagArray[1] = new("myEvent.TimeStampNullable", myEvent?.TimeStampNullable?.ToString());
        state.TagArray[0] = new("{OriginalFormat}", "Event triggered!");

        logger.Log(
            global::Microsoft.Extensions.Logging.LogLevel.Information,
            new(1, nameof(MyLogMessage)),
            state,
            null,
            [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "8.9.0.0")] static string (s, _) =>
            {
                return "Event triggered!";
            });

        state.Clear();
    }
}

Regression?

Unknown

Known Workarounds

No response

Configuration

It does not look specific to any architecture/.NET version.

.NET SDK:
 Version:           8.0.100
 Commit:            57efcf1350
 Workload version:  8.0.100-manifests.6c33ef20

Runtime Environment:
 OS Name:     Mac OS X
 OS Platform: Darwin
 RID:         osx-arm64
 Base Path:   /usr/local/share/dotnet/sdk/8.0.100/

.NET workloads installed:
 Workload version: 8.0.100-manifests.6c33ef20
There are no installed workloads to display.

Host:
  Version:      8.0.0
  Architecture: arm64
  Commit:       5535e31a71

.NET SDKs installed:
  6.0.405 [/usr/local/share/dotnet/sdk]
  7.0.101 [/usr/local/share/dotnet/sdk]
  7.0.102 [/usr/local/share/dotnet/sdk]
  8.0.100 [/usr/local/share/dotnet/sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 6.0.13 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.1 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.2 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 6.0.13 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.1 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.2 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.0 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]

Other architectures found:
  x64   [/usr/local/share/dotnet/x64]
    registered at [/etc/dotnet/install_location_x64]

Environment variables:
  Not set

global.json file:
  Not found

Learn more:
  https://aka.ms/dotnet/info

Download .NET:
  https://aka.ms/dotnet/download

Other information

No response

@rwoll rwoll added bug This issue describes a behavior which is not expected - a bug. untriaged labels Sep 9, 2024
@RussKie
Copy link
Member

RussKie commented Sep 9, 2024

@dariusclay please triage

rwoll added a commit to rwoll/dotnet-extensions that referenced this issue Sep 11, 2024
rwoll added a commit to rwoll/dotnet-extensions that referenced this issue Sep 11, 2024
@rwoll
Copy link
Contributor Author

rwoll commented Sep 11, 2024

@RussKie and @dariusclay - I've opened a PR with a test case: #5416

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-compliance bug This issue describes a behavior which is not expected - a bug.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants