Special-case strings to make them unquoted and add tests for custom formatter

Author: aradalvand

src/Serilog.Sinks.OpenTelemetry/Sinks/OpenTelemetry/Formatting/CleanMessageTemplateFormatter.cs

@@ -93,6 +93,9 @@ static void RenderPropertyValueUnaligned(LogEventPropertyValue propertyValue, Te
             return;
         }
 
+        if (scalar.Value is string && format is null or "")
+            format = "l"; // NOTE: Uses the literal format to yield unquoted strings
+
         scalar.Render(output, format, formatProvider);
     }
 }

test/Serilog.Sinks.OpenTelemetry.Tests/CleanMessageTemplateFormatterTests.cs

@@ -17,7 +17,7 @@ public void FormatsEmbeddedStringsWithoutQuoting()
         };
 
         var actual = CleanMessageTemplateFormatter.Format(template, properties, null);
-        
+
         // The default formatter would produce "Hello, \"world\"!" here.
         Assert.Equal("Hello, world!", actual);
     }
@@ -28,17 +28,103 @@ public void FormatsEmbeddedStructuresAsJson()
         var template = new MessageTemplateParser().Parse("Received {Payload}");
         var properties = new Dictionary<string, LogEventPropertyValue>
         {
-            ["Payload"] = new StructureValue(new []
-            {
+            ["Payload"] = new StructureValue(
+            [
                 // Particulars of the JSON structure are unimportant, this is handed of to Serilog's default
                 // JSON value formatter.
                 new LogEventProperty("a", new ScalarValue(42))
-            })
+            ])
         };
 
         var actual = CleanMessageTemplateFormatter.Format(template, properties, null);
-        
+
         // The default formatter would produce "Received {a = 42}" here.
         Assert.Equal("Received {\"a\":42}", actual);
     }
+
+    [Fact]
+    public void CustomFormatterWorksForScalarValues()
+    {
+        var template = new MessageTemplateParser().Parse("Event occurred at: {Timestamp}");
+        var timestamp = new DateTime(2024, 1, 15, 14, 30, 45);
+        var properties = new Dictionary<string, LogEventPropertyValue>
+        {
+            ["Timestamp"] = new ScalarValue(timestamp)
+        };
+
+        var formatProvider = new CustomDateTimeFormatProvider();
+        var actual = CleanMessageTemplateFormatter.Format(template, properties, formatProvider);
+
+        // The CustomDateTimeFormatProvider should be invoked to format the DateTime object
+        Assert.Equal("Event occurred at: CUSTOM(2024-01-15 14:30:45)", actual);
+    }
+
+    [Fact]
+    public void CustomFormatterWorksWithMultipleScalarValues()
+    {
+        var template = new MessageTemplateParser().Parse("Events: {Start} and {End}");
+        var start = new DateTime(2024, 1, 15, 9, 0, 0);
+        var end = new DateTime(2024, 1, 15, 17, 0, 0);
+        var properties = new Dictionary<string, LogEventPropertyValue>
+        {
+            ["Start"] = new ScalarValue(start),
+            ["End"] = new ScalarValue(end)
+        };
+
+        var formatProvider = new CustomDateTimeFormatProvider();
+        var actual = CleanMessageTemplateFormatter.Format(template, properties, formatProvider);
+
+        Assert.Equal($"Events: CUSTOM(2024-01-15 09:00:00) and CUSTOM(2024-01-15 17:00:00)", actual);
+    }
+
+    [Fact]
+    public void CustomFormatterWorksWithMixedTypes()
+    {
+        var template = new MessageTemplateParser().Parse("Event at {Timestamp} with {Count} items");
+        var timestamp = new DateTime(2024, 1, 15, 14, 30, 45);
+        var properties = new Dictionary<string, LogEventPropertyValue>
+        {
+            ["Timestamp"] = new ScalarValue(timestamp),
+            ["Count"] = new ScalarValue(42)
+        };
+
+        var formatProvider = new CustomDateTimeFormatProvider();
+        var actual = CleanMessageTemplateFormatter.Format(template, properties, formatProvider);
+
+        // NOTE: DateTime should be custom formatted, Count should use default formatting
+        Assert.Equal("Event at CUSTOM(2024-01-15 14:30:45) with 42 items", actual);
+    }
+
+    [Fact]
+    public void CustomFormatterWorksWithAlignment()
+    {
+        var template = new MessageTemplateParser().Parse("Event: {Timestamp,30}");
+        var timestamp = new DateTime(2024, 1, 15, 14, 30, 45);
+        var properties = new Dictionary<string, LogEventPropertyValue>
+        {
+            ["Timestamp"] = new ScalarValue(timestamp)
+        };
+
+        var formatProvider = new CustomDateTimeFormatProvider();
+        var actual = CleanMessageTemplateFormatter.Format(template, properties, formatProvider);
+
+        var expected = $"Event:    CUSTOM(2024-01-15 14:30:45)";
+        Assert.Equal(expected, actual);
+    }
+}
+
+class CustomDateTimeFormatProvider : IFormatProvider, ICustomFormatter
+{
+    public const string DateTimeFormatting = "CUSTOM-DATE-TIME-FORMATTING";
+    public object? GetFormat(Type? formatType) =>
+        formatType == typeof(ICustomFormatter)
+            ? this
+            : null;
+
+    public string Format(string? format, object? arg, IFormatProvider? formatProvider) => arg switch
+    {
+        DateTime dateTime => $"CUSTOM({dateTime:yyyy-MM-dd HH:mm:ss})",
+        IFormattable formattable => formattable.ToString(format, formatProvider),
+        _ => arg?.ToString() ?? ""
+    };
 }

test/Serilog.Sinks.OpenTelemetry.Tests/OpenTelemetryLogsSinkTests.cs

@@ -16,7 +16,7 @@ public async Task DefaultScopeIsNull()
         var scopeLogs = Assert.Single(resourceLogs.ScopeLogs);
         Assert.Null(scopeLogs.Scope);
     }
-    
+
     [Fact]
     public async Task SourceContextNameIsInstrumentationScope()
     {
@@ -27,7 +27,7 @@ public async Task SourceContextNameIsInstrumentationScope()
         var scopeLogs = Assert.Single(resourceLogs.ScopeLogs);
         Assert.Equal(contextType.FullName, scopeLogs.Scope.Name);
     }
-    
+
     [Fact]
     public async Task ScopeLogsAreGrouped()
     {
@@ -47,10 +47,26 @@ public async Task ScopeLogsAreGrouped()
         Assert.Single(resourceLogs.ScopeLogs.Single(r => r.Scope == null).LogRecords);
     }
 
-    static async Task<ExportLogsServiceRequest> ExportAsync(IReadOnlyCollection<LogEvent> events)
+    [Fact]
+    public async Task CustomFormatterSupportedEndToEnd()
+    {
+        var timestamp = new DateTime(2024, 6, 15, 10, 30, 0);
+
+        var events = CollectingSink.Collect(log =>
+            log.Information("Event occurred at: {Timestamp}", timestamp));
+
+        var request = await ExportAsync(events, new CustomDateTimeFormatProvider());
+        var resourceLogs = Assert.Single(request.ResourceLogs);
+        var scopeLogs = Assert.Single(resourceLogs.ScopeLogs);
+        var logRecord = Assert.Single(scopeLogs.LogRecords);
+
+        Assert.Equal($"Event occurred at: CUSTOM(2024-06-15 10:30:00)", logRecord.Body.StringValue);
+    }
+
+    static async Task<ExportLogsServiceRequest> ExportAsync(IReadOnlyCollection<LogEvent> events, IFormatProvider? formatProvider = null)
     {
         var exporter = new CollectingExporter();
-        var sink = new OpenTelemetryLogsSink(exporter, null, new Dictionary<string, object>(), OpenTelemetrySinkOptions.DefaultIncludedData);
+        var sink = new OpenTelemetryLogsSink(exporter, formatProvider, new Dictionary<string, object>(), OpenTelemetrySinkOptions.DefaultIncludedData);
         await sink.EmitBatchAsync(events);
         return Assert.Single(exporter.ExportLogsServiceRequests);
     }