Merge pull request #40 from lmanners/master

Add support for logging structured data

src/ZeroLog.Tests/Extensions.cs

@@ -0,0 +1,10 @@
+using System.Text.Formatting;
+
+namespace ZeroLog.Tests
+{
+    internal static class Extensions
+    {
+        public static void WriteToStringBuffer(this IInternalLogEvent logEvent, StringBuffer stringBuffer)
+            => logEvent.WriteToStringBuffer(stringBuffer, new KeyValuePointerBuffer());
+    }
+}

src/ZeroLog.Tests/LogEventTests.EdgeCases.cs

@@ -40,7 +40,9 @@ public void should_truncate_ascii_string_if_buffer_is_not_large_enough()
         }
 
         [Test]
-        public void should_ignore_ascii_string_if_buffer_is_not_large_enough_for_header([Range(_bufferSize - 2 * _asciiHeaderSize, _bufferSize)] int firstStringLength)
+        public void should_ignore_ascii_string_if_buffer_is_not_large_enough_for_header(
+            [Range(_bufferSize - 2 * _asciiHeaderSize, _bufferSize)]
+            int firstStringLength)
         {
             var largeString1 = new string('a', firstStringLength);
             var asciiBytes1 = Encoding.ASCII.GetBytes(largeString1);
@@ -212,6 +214,18 @@ public void should_ignore_append_time_span_if_buffer_is_full()
             Check.That(string.IsNullOrWhiteSpace(_output.ToString()));
         }
 
+        [Test]
+        public void should_ignore_append_key_values_if_buffer_is_full()
+        {
+            FillBufferWithWhiteSpaces();
+            _logEvent.AppendKeyValue("key1", (string)null)
+                     .AppendKeyValue("key2", "val2")
+                     .AppendKeyValue("key3", 3);
+            _logEvent.WriteToStringBuffer(_output);
+
+            Check.That(string.IsNullOrWhiteSpace(_output.ToString()));
+        }
+
         private void FillBufferWithWhiteSpaces()
         {
             var largeString = new string(' ', _bufferSize);

src/ZeroLog.Tests/LogEventTests.Enum.cs

@@ -39,6 +39,50 @@ public void should_append_null_enum()
             Assert.AreEqual("null", _output.ToString());
         }
 
+        [Test]
+        public void should_append_enum_key_value()
+        {
+            LogManager.RegisterEnum(typeof(TestEnum));
+
+            _logEvent.AppendKeyValue("myKey", TestEnum.Bar);
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual(" ~~ { \"myKey\": \"Bar\" }", _output.ToString());
+        }
+
+        [Test]
+        public void should_append_nullable_enum_key_value()
+        {
+            LogManager.RegisterEnum(typeof(TestEnum));
+
+            _logEvent.AppendKeyValue("myKey", (TestEnum?)TestEnum.Bar);
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual(" ~~ { \"myKey\": \"Bar\" }", _output.ToString());
+        }
+
+        [Test]
+        public void should_append_null_enum_key_value()
+        {
+            LogManager.RegisterEnum(typeof(TestEnum));
+
+            _logEvent.AppendKeyValue("myKey", (TestEnum?)null);
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual(" ~~ { \"myKey\": null }", _output.ToString());
+        }
+
+        [Test]
+        public void should_append_unknown_enum_key_value()
+        {
+            LogManager.RegisterEnum(typeof(TestEnum));
+
+            _logEvent.AppendKeyValue("myKey", (TestEnum)(-42));
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual(" ~~ { \"myKey\": -42 }", _output.ToString());
+        }
+
         [Test]
         public void should_append_enum_generic()
         {

src/ZeroLog.Tests/LogEventTests.KeyValues.cs

@@ -0,0 +1,208 @@
+using System;
+using NUnit.Framework;
+
+namespace ZeroLog.Tests
+{
+    public partial class LogEventTests
+    {
+        [Test]
+        public void should_append_single_key_value()
+        {
+            _logEvent.AppendKeyValue("myKey", "myValue");
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual(" ~~ { \"myKey\": \"myValue\" }", _output.ToString());
+        }
+
+        [Test]
+        public void should_append_multiple_key_values()
+        {
+            _logEvent.AppendKeyValue("myKey", "myValue");
+            _logEvent.AppendKeyValue("otherKey", 2);
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual(" ~~ { \"myKey\": \"myValue\", \"otherKey\": 2 }", _output.ToString());
+        }
+
+        [Test]
+        public void should_append_formatted_string_mixed_with_key_values()
+        {
+            // TODO(lmanners): There are more edge cases here.
+            _logEvent.AppendKeyValue("myKey", "myValue");
+            _logEvent.AppendFormat("Some {} message");
+            _logEvent.Append("formatted");
+            _logEvent.AppendKeyValue("otherKey", 2);
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual("Some formatted message ~~ { \"myKey\": \"myValue\", \"otherKey\": 2 }", _output.ToString());
+        }
+
+        [Test]
+        public void should_be_chainable()
+        {
+            _logEvent.AppendKeyValue("myKey", 1.1f).AppendKeyValue("otherKey", new Guid());
+            _logEvent.Append("message");
+            _logEvent.WriteToStringBuffer(_output);
+
+            Assert.AreEqual("message ~~ { \"myKey\": 1.1, \"otherKey\": \"00000000-0000-0000-0000-000000000000\" }", _output.ToString());
+        }
+
+        [TestCase]
+        public void should_support_char()
+        {
+            _logEvent.AppendKeyValue("key1", 'a');
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"key1\": \"a\" }", _output.ToString());
+        }
+
+        [TestCase]
+        public void should_support_datetime()
+        {
+            _logEvent.AppendKeyValue("key1", DateTime.MinValue);
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"key1\": \"0001-01-01 00:00:00.000\" }", _output.ToString());
+        }
+
+        [TestCase]
+        public void should_support_boolean()
+        {
+            _logEvent.AppendKeyValue("key1", true).AppendKeyValue("key2", false);
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"key1\": true, \"key2\": false }", _output.ToString());
+        }
+
+        [TestCase]
+        public void should_support_single_null_key_value()
+        {
+            _logEvent.AppendKeyValue("key1", (int?)null);
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"key1\": null }", _output.ToString());
+        }
+
+        [TestCase]
+        public void should_support_null_string_key_value()
+        {
+            _logEvent.AppendKeyValue("key1", "val1")
+                     .AppendKeyValue("key2", (string)null)
+                     .AppendKeyValue("key3", 3);
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"key1\": \"val1\", \"key2\": null, \"key3\": 3 }", _output.ToString());
+        }
+
+        [TestCase]
+        public void should_support_number_types()
+        {
+            _logEvent.AppendKeyValue("byte", (byte)1)
+                     .AppendKeyValue("short", (short)2)
+                     .AppendKeyValue("int", 3)
+                     .AppendKeyValue("long", 4L)
+                     .AppendKeyValue("float", 5.5f)
+                     .AppendKeyValue("double", 6.6d)
+                     .AppendKeyValue("decimal", 6.6m);
+
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"byte\": 1, \"short\": 2, \"int\": 3, \"long\": 4, \"float\": 5.5, \"double\": 6.6, \"decimal\": 6.6 }",
+                            _output.ToString());
+        }
+
+        [TestCase]
+        public void should_handle_truncated_key_values()
+        {
+            _logEvent.Initialize(Level.Info, null, LogEventArgumentExhaustionStrategy.TruncateMessage);
+            for (var i = 0; i < 6; i++)
+            {
+                _logEvent.AppendKeyValue($"key{i}", $"value{i}");
+            }
+
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(
+                " ~~ { \"key0\": \"value0\", \"key1\": \"value1\", \"key2\": \"value2\", \"key3\": \"value3\", \"key4\": \"value4\" } [TRUNCATED]",
+                _output.ToString());
+        }
+
+        [TestCase]
+        public void should_allocate_space_for_more_key_values()
+        {
+            for (var i = 0; i < 6; i++)
+            {
+                _logEvent.AppendKeyValue($"key{i}", $"value{i}");
+            }
+
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(
+                " ~~ { \"key0\": \"value0\", \"key1\": \"value1\", \"key2\": \"value2\", \"key3\": \"value3\", \"key4\": \"value4\", \"key5\": \"value5\" }",
+                _output.ToString());
+        }
+
+        [TestCase('\\', "\\\\")]
+        [TestCase('"', "\\\"")]
+        [TestCase('\u0000', "\\u0000")]
+        [TestCase('\u0000', "\\u0000")]
+        [TestCase('\u0001', "\\u0001")]
+        [TestCase('\u0002', "\\u0002")]
+        [TestCase('\u0003', "\\u0003")]
+        [TestCase('\u0004', "\\u0004")]
+        [TestCase('\u0005', "\\u0005")]
+        [TestCase('\u0006', "\\u0006")]
+        [TestCase('\u0007', "\\u0007")]
+        [TestCase('\u0008', "\\b")]
+        [TestCase('\u0009', "\\t")]
+        [TestCase('\u000A', "\\n")]
+        [TestCase('\u000B', "\\u000b")]
+        [TestCase('\u000C', "\\f")]
+        [TestCase('\u000D', "\\r")]
+        [TestCase('\u000E', "\\u000e")]
+        [TestCase('\u000F', "\\u000f")]
+        [TestCase('\u0010', "\\u0010")]
+        [TestCase('\u0011', "\\u0011")]
+        [TestCase('\u0012', "\\u0012")]
+        [TestCase('\u0013', "\\u0013")]
+        [TestCase('\u0014', "\\u0014")]
+        [TestCase('\u0015', "\\u0015")]
+        [TestCase('\u0016', "\\u0016")]
+        [TestCase('\u0017', "\\u0017")]
+        [TestCase('\u0018', "\\u0018")]
+        [TestCase('\u0019', "\\u0019")]
+        [TestCase('\u001A', "\\u001a")]
+        [TestCase('\u001B', "\\u001b")]
+        [TestCase('\u001C', "\\u001c")]
+        [TestCase('\u001D', "\\u001d")]
+        [TestCase('\u001E', "\\u001e")]
+        [TestCase('\u001F', "\\u001f")]
+        public void should_handle_escaped_characters(char character, string expected)
+        {
+            _logEvent.AppendKeyValue("myKey", character);
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"myKey\": \"" + expected + "\" }", _output.ToString());
+        }
+
+        [TestCase]
+        public void should_handle_partially_truncated_key_value()
+        {
+            _logEvent.Initialize(Level.Info, null, LogEventArgumentExhaustionStrategy.TruncateMessage);
+
+            // This value 'consumes' one slot in the buffer. This will cause us to be out of space when appending the value for key4.
+            _logEvent.Append("msg");
+
+            for (var i = 0; i < 5; i++)
+            {
+                _logEvent.AppendKeyValue($"key{i}", $"value{i}");
+            }
+
+            _logEvent.WriteToStringBuffer(_output);
+
+            // 'key4' is not present because there wasn't space for its value.
+            Assert.AreEqual(
+                "msg ~~ { \"key0\": \"value0\", \"key1\": \"value1\", \"key2\": \"value2\", \"key3\": \"value3\" } [TRUNCATED]",
+                _output.ToString());
+        }
+
+        [TestCase]
+        public void should_escape_strings_for_json()
+        {
+            _logEvent.AppendKeyValue("key \\ \" \t \n", "Hello \u0001 \0 there");
+            _logEvent.WriteToStringBuffer(_output);
+            Assert.AreEqual(" ~~ { \"key \\\\ \\\" \\t \\n\": \"Hello \\u0001 \\u0000 there\" }", _output.ToString());
+        }
+    }
+}

src/ZeroLog.Tests/LogEventTests.Unmanaged.cs

@@ -38,7 +38,7 @@ public void should_append_unmanaged()
             LogManager.RegisterUnmanaged<UnmanagedStruct>();
 
             _logEvent.AppendUnmanaged(o);
-            _logEvent.WriteToStringBuffer(_output); 
+            _logEvent.WriteToStringBuffer(_output);
 
             Assert.AreEqual("1-2-3", _output.ToString());
         }

src/ZeroLog/ArgumentType.cs

@@ -20,5 +20,6 @@ internal enum ArgumentType : byte
         Enum,
         Null,
         Unmanaged,
+        KeyString,
     }
 }

src/ZeroLog/Config/JsonConfigurator.cs

@@ -52,6 +52,9 @@ private static void ConfigureGlobal(ZeroLogJsonConfiguration config)
 
             if (config.NullDisplayString != null)
                 LogManager.Config.NullDisplayString = config.NullDisplayString;
+
+            if (config.JsonSeparator != null)
+                LogManager.Config.JsonSeparator = config.JsonSeparator;
         }
 
         private static ZeroLogJsonConfiguration ConfigureResolver(string configFileFullPath, HierarchicalResolver resolver)

src/ZeroLog/Config/ZeroLogJsonConfiguration.cs

@@ -7,6 +7,7 @@ public class ZeroLogJsonConfiguration : IHierarchicalConfiguration
         public int LogEventArgumentCapacity { get; set; }
         public bool LazyRegisterEnums { get; set; }
         public string? NullDisplayString { get; set; }
+        public string? JsonSeparator { get; set; }
 
         public AppenderDefinition[] Appenders { get; set; } = new AppenderDefinition[0];
 

src/ZeroLog/EnumArg.cs

@@ -23,34 +23,17 @@ public EnumArg(IntPtr typeHandle, ulong value)
         [MethodImpl(MethodImplOptions.AggressiveInlining)]
         public void AppendTo(StringBuffer stringBuffer)
         {
-            var enumString = EnumCache.GetString(_typeHandle, _value, out var enumRegistered);
+            var enumString = GetString();
+
             if (enumString != null)
-            {
                 stringBuffer.Append(enumString);
-                return;
-            }
-
-            AppendToSlow(stringBuffer, enumRegistered);
+            else
+                AppendNumericValue(stringBuffer);
         }
 
         [MethodImpl(MethodImplOptions.NoInlining)]
-        private void AppendToSlow(StringBuffer stringBuffer, bool enumRegistered)
+        public void AppendNumericValue(StringBuffer stringBuffer)
         {
-            if (!enumRegistered && LogManager.Config.LazyRegisterEnums)
-            {
-                var type = TypeUtil.GetTypeFromHandle(_typeHandle);
-                if (type is null)
-                    return;
-
-                LogManager.RegisterEnum(type);
-                var enumString = EnumCache.GetString(_typeHandle, _value, out _);
-                if (enumString != null)
-                {
-                    stringBuffer.Append(enumString);
-                    return;
-                }
-            }
-
             if (_value <= long.MaxValue)
             {
                 stringBuffer.Append(_value, StringView.Empty);
@@ -62,5 +45,24 @@ private void AppendToSlow(StringBuffer stringBuffer, bool enumRegistered)
             else
                 stringBuffer.Append(_value, StringView.Empty);
         }
+
+        [MethodImpl(MethodImplOptions.AggressiveInlining)]
+        public string? GetString()
+            => EnumCache.GetString(_typeHandle, _value, out var enumRegistered)
+               ?? GetStringSlow(enumRegistered);
+
+        [MethodImpl(MethodImplOptions.NoInlining)]
+        private string? GetStringSlow(bool enumRegistered)
+        {
+            if (enumRegistered || !LogManager.Config.LazyRegisterEnums)
+                return null;
+
+            var type = TypeUtil.GetTypeFromHandle(_typeHandle);
+            if (type is null)
+                return null;
+
+            LogManager.RegisterEnum(type);
+            return EnumCache.GetString(_typeHandle, _value, out _);
+        }
     }
 }