fix: [LogProperties] avoid early ToString of Nullable Properties

src/Generators/Microsoft.Gen.Logging/Parsing/TypeSymbolExtensions.cs

@@ -15,6 +15,8 @@ internal static bool IsEnumerable(this ITypeSymbol sym, SymbolHolder symbols)
 
     internal static bool ImplementsIConvertible(this ITypeSymbol sym, SymbolHolder symbols)
     {
+        sym = sym.GetPossiblyNullWrappedType();
+
         foreach (var member in sym.GetMembers("ToString"))
         {
             if (member is IMethodSymbol ts)
@@ -36,6 +38,8 @@ internal static bool ImplementsIConvertible(this ITypeSymbol sym, SymbolHolder s
 
     internal static bool ImplementsIFormattable(this ITypeSymbol sym, SymbolHolder symbols)
     {
+        sym = sym.GetPossiblyNullWrappedType();
+
         foreach (var member in sym.GetMembers("ToString"))
         {
             if (member is IMethodSymbol ts)
@@ -57,7 +61,11 @@ internal static bool ImplementsIFormattable(this ITypeSymbol sym, SymbolHolder s
     }
 
     internal static bool ImplementsISpanFormattable(this ITypeSymbol sym, SymbolHolder symbols)
-        => symbols.SpanFormattableSymbol != null && (sym.ImplementsInterface(symbols.SpanFormattableSymbol) || SymbolEqualityComparer.Default.Equals(sym, symbols.SpanFormattableSymbol));
+    {
+        sym = sym.GetPossiblyNullWrappedType();
+
+        return symbols.SpanFormattableSymbol != null && (sym.ImplementsInterface(symbols.SpanFormattableSymbol) || SymbolEqualityComparer.Default.Equals(sym, symbols.SpanFormattableSymbol));
+    }
 
     internal static bool IsSpecialType(this ITypeSymbol typeSymbol, SymbolHolder symbols)
         => typeSymbol.SpecialType != SpecialType.None ||
@@ -82,4 +90,13 @@ internal static bool HasCustomToString(this ITypeSymbol type)
         return false;
     }
 
+    internal static ITypeSymbol GetPossiblyNullWrappedType(this ITypeSymbol sym)
+    {
+        if (sym is INamedTypeSymbol namedTypeSymbol && namedTypeSymbol.IsGenericType && namedTypeSymbol.OriginalDefinition.SpecialType == SpecialType.System_Nullable_T)
+        {
+            return namedTypeSymbol.TypeArguments[0];
+        }
+
+        return sym;
+    }
 }

test/Generators/Microsoft.Gen.Logging/Generated/LogPropertiesTests.cs

@@ -313,6 +313,45 @@ public void LogPropertiesInTemplateTest()
         _logger.Collector.LatestRecord.StructuredState.Should().NotBeNull().And.Equal(expectedState);
     }
 
+    [Fact]
+    public void LogPropertiesTestNullablePropertyInClass()
+    {
+        var now = new DateTime(2024, 1, 1, 0, 0, 0, DateTimeKind.Utc);
+        var classToLog = new MyClassWithNullableProperty { NullableDateTime = now, NonNullableDateTime = now };
+        LogMethodNullablePropertyInClassMatchesNonNullable(_logger, classToLog);
+        Assert.Equal(1, _logger.Collector.Count);
+        Assert.Equal(LogLevel.Information, _logger.Collector.LatestRecord.Level);
+        Assert.Equal($"Testing nullable property within class here...", _logger.Collector.LatestRecord.Message);
+        var expectedState = new Dictionary<string, string?>
+        {
+            // Note that, regardless of nullability, the datetime fields SHOULD match given the same, non-null input.
+            ["classWithNullablePropertyParam.NullableDateTime"] = "01/01/2024 00:00:00",
+            ["classWithNullablePropertyParam.NonNullableDateTime"] = "01/01/2024 00:00:00",
+            ["{OriginalFormat}"] = "Testing nullable property within class here..."
+        };
+
+        _logger.Collector.LatestRecord.StructuredState.Should().NotBeNull().And.Equal(expectedState);
+    }
+
+    [Fact]
+    public void LogPropertiesTestNullablePropertyInClass_WhenNull()
+    {
+        var now = new DateTime(2024, 1, 1, 0, 0, 0, DateTimeKind.Utc);
+        var classToLog = new MyClassWithNullableProperty { NullableDateTime = null, NonNullableDateTime = now };
+        LogMethodNullablePropertyInClassMatchesNonNullable(_logger, classToLog);
+        Assert.Equal(1, _logger.Collector.Count);
+        Assert.Equal(LogLevel.Information, _logger.Collector.LatestRecord.Level);
+        Assert.Equal($"Testing nullable property within class here...", _logger.Collector.LatestRecord.Message);
+        var expectedState = new Dictionary<string, string?>
+        {
+            ["classWithNullablePropertyParam.NullableDateTime"] = null,
+            ["classWithNullablePropertyParam.NonNullableDateTime"] = "01/01/2024 00:00:00",
+            ["{OriginalFormat}"] = "Testing nullable property within class here..."
+        };
+
+        _logger.Collector.LatestRecord.StructuredState.Should().NotBeNull().And.Equal(expectedState);
+    }
+
     [Fact]
     public void LogPropertiesNonStaticClassTest()
     {
@@ -458,7 +497,7 @@ public void LogPropertiesInterfaceArgument()
         Assert.Equal(1, _logger.Collector.Count);
         var latestRecord = _logger.Collector.LatestRecord;
         Assert.Null(latestRecord.Exception);
-        Assert.Equal(5, latestRecord.Id.Id);
+        Assert.Equal(6, latestRecord.Id.Id);
         Assert.Equal(LogLevel.Information, latestRecord.Level);
         Assert.Equal("Testing interface-typed argument here...", latestRecord.Message);
 

test/Generators/Microsoft.Gen.Logging/TestClasses/LogPropertiesExtensions.cs

@@ -111,6 +111,12 @@ public MyCustomStruct(object _)
             }
         }
 
+        public class MyClassWithNullableProperty
+        {
+            public DateTime? NullableDateTime { get; set; }
+            public DateTime NonNullableDateTime { get; set; }
+        }
+
         public struct MyTransitiveStruct
         {
             public DateTimeOffset DateTimeOffsetProperty { get; set; } = DateTimeOffset.UtcNow;
@@ -230,10 +236,13 @@ public override string ToString()
         [LoggerMessage(4, LogLevel.Information, "Testing explicit nullable struct here...")]
         public static partial void LogMethodExplicitNullableStruct(ILogger logger, [LogProperties] Nullable<MyCustomStruct> structParam);
 
+        [LoggerMessage(5, LogLevel.Information, "Testing nullable property within class here...")]
+        public static partial void LogMethodNullablePropertyInClassMatchesNonNullable(ILogger logger, [LogProperties] MyClassWithNullableProperty classWithNullablePropertyParam);
+
         [LoggerMessage]
         public static partial void LogMethodDefaultAttrCtor(ILogger logger, LogLevel level, [LogProperties] ClassAsParam? complexParam);
 
-        [LoggerMessage(5, LogLevel.Information, "Testing interface-typed argument here...")]
+        [LoggerMessage(6, LogLevel.Information, "Testing interface-typed argument here...")]
         public static partial void LogMethodInterfaceArg(ILogger logger, [LogProperties] IMyInterface complexParam);
     }
 }

test/Generators/Microsoft.Gen.Logging/Unit/ParserTests.LogProperties.cs

@@ -1,8 +1,14 @@
 // Licensed to the .NET Foundation under one or more agreements.
 // The .NET Foundation licenses this file to you under the MIT license.
 
+using System;
+using System.IO;
+using System.Reflection;
 using System.Threading.Tasks;
+using Microsoft.Extensions.Logging;
 using Microsoft.Gen.Logging.Parsing;
+using Microsoft.Gen.Shared;
+using VerifyXunit;
 using Xunit;
 
 namespace Microsoft.Gen.Logging.Test;
@@ -433,4 +439,55 @@ static partial void M0(this ILogger logger,
                     MyRecordStruct p6);
             }", DiagDescriptors.DefaultToString);
     }
+
+    [Fact]
+    public async Task ClassWithNullableProperty()
+    {
+        string source = @"
+                namespace Test
+                {
+                    using System;
+
+                    using Microsoft.Extensions.Logging;
+
+                    internal static class LoggerUtils
+                    {
+                        public class MyClassWithNullableProperty
+                        {
+                            public DateTime? NullableDateTime { get; set; }
+                            public DateTime NonNullableDateTime { get; set; }
+                        }
+
+                        partial class MyLogger
+                        {
+                            [LoggerMessage(0, LogLevel.Information, ""Testing nullable property within class here..."")]
+                            public static partial void LogMethodNullablePropertyInClassMatchesNonNullable(ILogger logger, [LogProperties] MyClassWithNullableProperty classWithNullablePropertyParam);
+                        }
+                    }
+                }";
+
+#if NET6_0_OR_GREATER
+        var symbols = new[] { "NET7_0_OR_GREATER", "NET6_0_OR_GREATER", "NET5_0_OR_GREATER" };
+#else
+        var symbols = new[] { "NET5_0_OR_GREATER" };
+#endif
+
+        var (d, r) = await RoslynTestUtils.RunGenerator(
+            new LoggingGenerator(),
+            new[]
+            {
+                Assembly.GetAssembly(typeof(ILogger))!,
+                Assembly.GetAssembly(typeof(LogPropertiesAttribute))!,
+                Assembly.GetAssembly(typeof(LoggerMessageAttribute))!,
+                Assembly.GetAssembly(typeof(DateTime))!,
+            },
+            [source],
+            symbols)
+            .ConfigureAwait(false);
+
+        Assert.Empty(d);
+        await Verifier.Verify(r[0].SourceText.ToString())
+            .AddScrubber(_ => _.Replace(GeneratorUtilities.CurrentVersion, "VERSION"))
+            .UseDirectory(Path.Combine("..", "Verified"));
+    }
 }

test/Generators/Microsoft.Gen.Logging/Verified/ParserTests.ClassWithNullableProperty.verified.txt

@@ -0,0 +1,44 @@
+
+// <auto-generated/>
+#nullable enable
+#pragma warning disable CS1591 // Compensate for https://github.com/dotnet/roslyn/issues/54103
+
+namespace Test
+{
+    partial class LoggerUtils
+    {
+        partial class MyLogger
+        {
+            /// <summary>
+            /// Logs "Testing nullable property within class here..." at "Information" level.
+            /// </summary>
+            [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "VERSION")]
+            public static partial void LogMethodNullablePropertyInClassMatchesNonNullable(global::Microsoft.Extensions.Logging.ILogger logger, global::Test.LoggerUtils.MyClassWithNullableProperty classWithNullablePropertyParam)
+            {
+                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("classWithNullablePropertyParam.NullableDateTime", classWithNullablePropertyParam?.NullableDateTime);
+                state.TagArray[1] = new("classWithNullablePropertyParam.NonNullableDateTime", classWithNullablePropertyParam?.NonNullableDateTime);
+                state.TagArray[0] = new("{OriginalFormat}", "Testing nullable property within class here...");
+
+                logger.Log(
+                    global::Microsoft.Extensions.Logging.LogLevel.Information,
+                    new(0, nameof(LogMethodNullablePropertyInClassMatchesNonNullable)),
+                    state,
+                    null,
+                    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "VERSION")] static string (s, _) =>
+                    {
+                        return "Testing nullable property within class here...";
+                    });
+
+                state.Clear();
+            }
+        }
+    }
+}