More tests & fixes to validate that we correctly format

.github/workflows/release.yml

@@ -6,7 +6,7 @@ env:
 on:
     push:
         tags:
-            - "*"
+            - '*'
 
 jobs:
     build:
@@ -18,7 +18,7 @@ jobs:
             - name: Setup .NET Core
               uses: actions/setup-dotnet@v1
               with:
-                  dotnet-version: "7.0.x"
+                  dotnet-version: '8.0.x'
             - name: Install dependencies
               run: dotnet restore
             - name: Build

Serilog.Sinks.LogtailSys.Tests/LogtailFormatterTests.cs

@@ -0,0 +1,190 @@
+using System.Text.RegularExpressions;
+using FluentAssertions;
+using Serilog.Events;
+using Serilog.Parsing;
+using Serilog.Sinks.Logtail;
+using Xunit.Abstractions;
+
+namespace Serilog.Sinks.LogtailSys.Tests;
+public class LogtailFormatterTests
+    {
+        private const string NILVALUE = "-";
+        private const string LogtailSD = "[Logtail=\"SOURCE_TOKEN\"]";
+        const string APP_NAME = "TestApp";
+        const string SOURCE_CONTEXT = "TestCtx";
+        private static readonly string Host = Environment.MachineName.WithMaxLength(255);
+
+        private readonly ITestOutputHelper output;
+        private readonly LogtailFormatter formatter = new(
+           "Logtail", "SOURCE_TOKEN", "Parameters", Facility.User, APP_NAME);
+        private readonly DateTimeOffset timestamp;
+        private readonly Regex regex;
+
+        public LogtailFormatterTests(ITestOutputHelper output)
+        {
+            this.output = output;
+
+            // Prepare a regex object that can be used to check the output format
+            // NOTE: The regex is in a text file instead of as a variable - it's a but large, and all the escaping required to
+            // have it as a variable just makes it hard to grok
+            this.regex = new Regex(File.ReadAllText("LogtailRegex.txt"), RegexOptions.IgnorePatternWhitespace | RegexOptions.ExplicitCapture);
+
+            // Timestamp used in tests
+            var instant = new DateTime(2013, 12, 19, 4, 1, 2, 357) + TimeSpan.FromTicks(8523);
+            this.timestamp = new DateTimeOffset(instant);
+        }
+
+        [Fact]
+        public void Should_format_message_without_structured_data()
+        {
+            var template = new MessageTemplateParser().Parse("This is a test message");
+            var infoEvent = new LogEvent(this.timestamp, LogEventLevel.Information, null, template, Enumerable.Empty<LogEventProperty>());
+
+            var formatted = this.formatter.FormatMessage(infoEvent);
+            this.output.WriteLine($"RFC5424 without structured data: {formatted}");
+
+            var match = this.regex.Match(formatted);
+            match.Success.Should().BeTrue();
+
+            match.Groups["pri"].Value.Should().Be("<14>");
+            match.Groups["ver"].Value.Should().Be("1");
+            match.Groups["timestamp"].Value.Should().Be($"2013-12-19T04:01:02.357852{this.timestamp:zzz}");
+            match.Groups["app"].Value.Should().Be(APP_NAME);
+            match.Groups["host"].Value.Should().Be(Host);
+            match.Groups["proc"].Value.ToInt().Should().BeGreaterThan(0);
+            match.Groups["msgid"].Value.Should().Be(NILVALUE);
+            match.Groups["ltail"].Value.Should().Be(LogtailSD); // Since logtail is present, this is fine.
+            match.Groups["sd"].Value.Should().Be(""); // Since logtail is present, this is fine.
+            match.Groups["msg"].Value.Should().Be("This is a test message");
+
+            this.output.WriteLine($"FORMATTED: {formatted}");
+        }
+
+        [Fact]
+        public void Should_format_message_with_structured_data()
+        {
+            const string testVal = "A Value";
+
+            var properties = new List<LogEventProperty> {
+                new LogEventProperty("AProperty", new ScalarValue(testVal)),
+                new LogEventProperty("AnotherProperty", new ScalarValue("AnotherValue")),
+                new LogEventProperty("SourceContext", new ScalarValue(SOURCE_CONTEXT))
+            };
+
+            var template = new MessageTemplateParser().Parse("This is a test message with val {AProperty}");
+            var ex = new ArgumentException("Test");
+            var warnEvent = new LogEvent(this.timestamp, LogEventLevel.Warning, ex, template, properties);
+
+            var formatted = this.formatter.FormatMessage(warnEvent);
+            this.output.WriteLine($"RFC5424 with structured data: {formatted}");
+
+            var match = this.regex.Match(formatted);
+            match.Success.Should().BeTrue();
+
+            match.Groups["pri"].Value.Should().Be("<12>");
+            match.Groups["ver"].Value.Should().Be("1");
+            match.Groups["timestamp"].Value.Should().Be($"2013-12-19T04:01:02.357852{this.timestamp:zzz}");
+            match.Groups["app"].Value.Should().Be(APP_NAME);
+            match.Groups["host"].Value.Should().Be(Host);
+            match.Groups["proc"].Value.ToInt().Should().BeGreaterThan(0);
+            match.Groups["msgid"].Value.Should().Be(SOURCE_CONTEXT);
+            match.Groups["sd"].Value.Should().NotBe(NILVALUE);
+            match.Groups["ltail"].Value.Should().Be(LogtailSD); // Since logtail is present, this is fine.
+            match.Groups["msg"].Value.Should().Be($"This is a test message with val \"{testVal}\"");
+        }
+
+        [Fact]
+        public void Should_choose_another_msgId_provider()
+        {
+            const string testProperty = "AProperty";
+            const string testVal = "AValue";
+            const string msgIdPropertyName = testProperty;
+            var customFormatter = new LogtailFormatter("Logtail", "SOURCE_TOKEN", "Parameters", Facility.User, APP_NAME, null, msgIdPropertyName);
+
+            var properties = new List<LogEventProperty>
+            {
+                new LogEventProperty(testProperty, new ScalarValue(testVal)),
+                new LogEventProperty("AnotherProperty", new ScalarValue("AnotherValue")),
+                new LogEventProperty("SourceContext", new ScalarValue(SOURCE_CONTEXT))
+            };
+
+            var template = new MessageTemplateParser().Parse("This is a test message with val {AProperty}");
+            var ex = new ArgumentException("Test");
+            var warnEvent = new LogEvent(this.timestamp, LogEventLevel.Warning, ex, template, properties);
+
+            var formatted = customFormatter.FormatMessage(warnEvent);
+            this.output.WriteLine($"RFC5424 with structured data: {formatted}");
+
+            var match = this.regex.Match(formatted);
+            match.Success.Should().BeTrue();
+
+            match.Groups["pri"].Value.Should().Be("<12>");
+            match.Groups["ver"].Value.Should().Be("1");
+            match.Groups["timestamp"].Value.Should().Be($"2013-12-19T04:01:02.357852{this.timestamp:zzz}");
+            match.Groups["app"].Value.Should().Be(APP_NAME);
+            match.Groups["host"].Value.Should().Be(Host);
+            match.Groups["proc"].Value.ToInt().Should().BeGreaterThan(0);
+            match.Groups["msgid"].Value.Should().Be(testVal);
+            match.Groups["sd"].Value.Should().NotBe(NILVALUE);
+            match.Groups["ltail"].Value.Should().Be(LogtailSD); // Since logtail is present, this is fine.
+            match.Groups["msg"].Value.Should().Be($"This is a test message with val \"{testVal}\"");
+        }
+
+        /// <summary>
+        /// RFC5424 rules:
+        /// - Property names must be >= 1 and &lt;= 32 characters and may only contain printable ASCII
+        ///   characters as defined by PRINTUSASCII
+        ///
+        /// - Property values must escape the characters '"', '\' and ']' with a backslash '\'
+        ///
+        /// - MSGID (source context) must be >= 1 and &lt;= 32 characters and may only contain printable ASCII
+        ///   characters as defined by PRINTUSASCII
+        /// </summary>
+        [Fact]
+        public void Should_clean_invalid_strings()
+        {
+            var properties = new List<LogEventProperty> {
+                new LogEventProperty("安森Test", new ScalarValue(@"test")),
+                new LogEventProperty("APropertyNameThatIsLongerThan32Characters", new ScalarValue(@"A value \contain]ing ""quotes"" to test")),
+                new LogEventProperty("SourceContext", new ScalarValue("安森 A string that is longer than 32 characters"))
+            };
+
+            var template = new MessageTemplateParser().Parse("This is a test message");
+            var infoEvent = new LogEvent(this.timestamp, LogEventLevel.Information, null, template, properties);
+
+            var formatted = this.formatter.FormatMessage(infoEvent);
+            this.output.WriteLine($"RFC5424: {formatted}");
+
+            var match = this.regex.Match(formatted);
+            match.Success.Should().BeTrue();
+
+            match.Groups["msgid"].Value.Length.Should().Be(32);
+
+            // Spaces and anything other than printable ASCII should have been removed
+            match.Groups["msgid"].Value.Should().StartWith("Astringthatis");
+            match.Groups["ltail"].Value.Should().Be(LogtailSD); // Since logtail is present, this is fine.
+
+            // '"', '\' and ']' in property values should have been escaped with a backslash '\'
+            Regex.IsMatch(match.Groups["sd"].Value, @"\\\\contain\\]ing\s\\""quotes\\""").Should().BeTrue();
+
+            // Property names have had spaces and anything other than printable ASCII should have been removed,
+            // and should have been truncated to 32 chars
+            Regex.IsMatch(match.Groups["sd"].Value, @"APropertyNameThatIsLongerThan32C="".*""\s").Should().BeTrue();
+        }
+
+        [Fact]
+        public void Should_override_log_host_name()
+        {
+            var template = new MessageTemplateParser().Parse("This is a test message");
+            var infoEvent = new LogEvent(this.timestamp, LogEventLevel.Information, null, template, Enumerable.Empty<LogEventProperty>());
+
+            const string hostname = "NewHostName";
+            var localFormatter = new LogtailFormatter("Logtail", "SOURCE_TOKEN", "Parameters", Facility.User, APP_NAME, null, "SourceContext", hostname);
+            var formatted = localFormatter.FormatMessage(infoEvent);
+
+            var match = this.regex.Match(formatted);
+            match.Success.Should().BeTrue();
+
+            match.Groups["host"].Value.Should().Be(hostname);
+        }
+    }

Serilog.Sinks.LogtailSys.Tests/LogtailRegex.txt

@@ -0,0 +1,25 @@
+^(?<pri><\d{1,3}>)
+(?<ver>\d)
+\s
+(?<timestamp>\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d+[+-]\d{2}:\d{2})
+\s
+(?<host>[\u0021-\u007E]{1,255})
+\s
+(?<app>[\u0021-\u007E]{1,48})
+\s
+(?<proc>[\u0021-\u007E]{1,128})
+\s
+(?<msgid>[\u0021-\u007E]{1,32})
+\s
+(?<ltail>(\[
+  (?<lvp>(((?![=\"\]\s])[\u0021-\u007E]{1,32}=".*?")+)
+)\]))
+(?<sd>(
+  \[
+    (?<sdid>((?![=\"\]\s])[\u0021-\u007E]){1,32})
+    \s
+    (?<kvp>(((?![=\"\]\s])[\u0021-\u007E]){1,32}=".+")+)
+  \]
+)?)
+\s
+(?<msg>.*)$

Serilog.Sinks.LogtailSys.Tests/Serilog.Sinks.LogtailSys.Tests.csproj

@@ -25,4 +25,10 @@
       <ProjectReference Include="..\Serilog.Sinks.LogtailSys\Serilog.Sinks.LogtailSys.csproj" />
     </ItemGroup>
 
+    <ItemGroup>
+      <None Update="LogtailRegex.txt">
+        <CopyToOutputDirectory>Always</CopyToOutputDirectory>
+      </None>
+    </ItemGroup>
+
 </Project>

Serilog.Sinks.LogtailSys/Formatters/LogtailFormatter.cs

@@ -113,21 +113,24 @@ private string GetMessageId(LogEvent logEvent)
 
         private string RenderStructuredData(LogEvent logEvent)
         {
-            var builder = new StringBuilder();
-            builder.Append($"{tokenKey}=\"{token}\"");
-            if (logEvent.Properties.Count is 0) 
-                return builder.ToString();
-
-            builder.Append($"[{dataName} ");
-            foreach (var property in logEvent.Properties)
-            {
-                var kvp = $"""
-                {RenderPropertyKey(property.Key)}="{RenderPropertyValue(property.Value)}"
-                """;
-                builder.Append(kvp);
-            }
-            builder.Append(']');
-            return builder.ToString();
+             var builder = new StringBuilder();
+             builder.Append($"[{tokenKey}=\"{token}\"]");
+             if (logEvent.Properties.Count is 0) 
+                 return builder.ToString();
+
+             builder.Append($"[{dataName} ");
+             var propertyLen = logEvent.Properties.Count;
+             foreach (var (i, property) in logEvent.Properties.Enumerate())
+             {
+                 var kvp = $"""
+                 {RenderPropertyKey(property.Key)}="{RenderPropertyValue(property.Value)}"
+                 """;
+                 builder.Append(kvp);
+                 if (i != propertyLen - 1)
+                     builder.Append(' ');
+             }
+             builder.Append(']');
+             return builder.ToString();
         }
 
         private static string RenderPropertyKey(string propertyKey)

Serilog.Sinks.LogtailSys/Sinks/EnumerableExtensions.cs

@@ -0,0 +1,19 @@
+using System.Collections.Generic;
+using System.Linq;
+
+namespace Serilog.Sinks.Logtail;
+
+public static class EnumerableExtensions
+{
+    /// <summary>
+    /// An enumerable that yields the current index and the element during enumeration.
+    /// </summary>
+    /// <typeparam name="T">Typeof item</typeparam>
+    /// <param name="input">Enumerable of T</param>
+    /// <returns>Tuple with current idx and the item at that idx</returns>
+    public static IEnumerable<(int Index, T Item)> Enumerate<T>(this IEnumerable<T> input)
+    {
+        int i = 0;
+        return input.Select(x => (i++, x));
+    }
+}