From 100d615389ccb4993f5eff8c32503e75815177f5 Mon Sep 17 00:00:00 2001 From: Lucas Trzesniewski Date: Wed, 26 Jun 2019 12:57:04 +0200 Subject: [PATCH] Gracefully handle exceptions in unmanaged struct formatting --- src/ZeroLog.Tests/LogEventTests.Unmanaged.cs | 37 +++++++++++++++++++- src/ZeroLog.Tests/LogManagerTests.cs | 33 +++++++++++++++++ src/ZeroLog/LogEvent.cs | 7 ++++ src/ZeroLog/UnmanagedArgHeader.cs | 10 +++--- 4 files changed, 81 insertions(+), 6 deletions(-) diff --git a/src/ZeroLog.Tests/LogEventTests.Unmanaged.cs b/src/ZeroLog.Tests/LogEventTests.Unmanaged.cs index d529069b..03a255df 100644 --- a/src/ZeroLog.Tests/LogEventTests.Unmanaged.cs +++ b/src/ZeroLog.Tests/LogEventTests.Unmanaged.cs @@ -1,8 +1,12 @@ -using System.Text.Formatting; +using System; +using System.Diagnostics.CodeAnalysis; +using System.Text.Formatting; using NUnit.Framework; namespace ZeroLog.Tests { + [SuppressMessage("ReSharper", "MemberCanBePrivate.Global")] + [SuppressMessage("ReSharper", "NotAccessedField.Global")] public partial class LogEventTests { public struct UnmanagedStruct : IStringFormattable @@ -455,5 +459,36 @@ public void should_append_nullable_unmanaged_byref_with_format() Assert.AreEqual("42[foo]", _output.ToString()); } + + public struct FailingUnmanagedStruct : IStringFormattable + { + public long A; + public int B; + public byte C; + + public void Format(StringBuffer buffer, StringView format) + { + buffer.Append("boom"); + throw new InvalidOperationException("Simulated failure"); + } + } + + [Test] + public void should_append_failing_unmanaged_as_unformatted() + { + var o = new FailingUnmanagedStruct + { + A = 1, + B = 2, + C = 3, + }; + + LogManager.RegisterUnmanaged(); + + _logEvent.AppendUnmanaged(o); + _logEvent.WriteToStringBufferUnformatted(_output); + + Assert.AreEqual("Unmanaged(0x01000000000000000200000003000000)", _output.ToString()); + } } } diff --git a/src/ZeroLog.Tests/LogManagerTests.cs b/src/ZeroLog.Tests/LogManagerTests.cs index f52efd67..bf00090a 100644 --- a/src/ZeroLog.Tests/LogManagerTests.cs +++ b/src/ZeroLog.Tests/LogManagerTests.cs @@ -1,6 +1,8 @@ using System; using System.Collections.Generic; +using System.Diagnostics.CodeAnalysis; using System.Linq; +using System.Text.Formatting; using System.Threading; using System.Threading.Tasks; using NFluent; @@ -11,6 +13,8 @@ namespace ZeroLog.Tests { [TestFixture] + [SuppressMessage("ReSharper", "MemberCanBePrivate.Global")] + [SuppressMessage("ReSharper", "NotAccessedField.Global")] public class LogManagerTests { private TestAppender _testAppender; @@ -228,6 +232,24 @@ public unsafe void should_not_throw_if_formatting_fails_when_appending_formatted Check.That(logMessage).Equals("An error occured during formatting: \"Hello\", False, 1, 'a', 2, 3, 4, 5, 6, 7, " + guid + ", 2017-02-24 16:51:51.000, 16:51:51, \"abc\", \"abc\", Friday"); } + [Test] + public void should_write_unformatted_unmanaged_struct_when_formatting_fails() + { + LogManager.RegisterUnmanaged(); + + var log = LogManager.GetLogger(typeof(LogManagerTests)); + var signal = _testAppender.SetMessageCountTarget(1); + + log.Info() + .AppendUnmanaged(new FailingUnmanagedStruct { Value = 42 }) + .Log(); + + signal.Wait(TimeSpan.FromMilliseconds(100)); + + var logMessage = _testAppender.LoggedMessages.Single(); + Check.That(logMessage).Equals("An error occured during formatting: Unmanaged(0x2a000000)"); + } + [Test] public void should_flush_appenders_when_not_logging_messages() { @@ -270,5 +292,16 @@ public void should_truncate_long_lines() var message = _testAppender.LoggedMessages.Single(); Check.That(message).IsEqualTo(new string('.', LogManager.OutputBufferSize - LogManager.Config.TruncatedMessageSuffix.Length) + LogManager.Config.TruncatedMessageSuffix); } + + public struct FailingUnmanagedStruct : IStringFormattable + { + public int Value; + + public void Format(StringBuffer buffer, StringView format) + { + buffer.Append("boom"); + throw new InvalidOperationException("Simulated failure"); + } + } } } diff --git a/src/ZeroLog/LogEvent.cs b/src/ZeroLog/LogEvent.cs index aeed0908..44d68679 100644 --- a/src/ZeroLog/LogEvent.cs +++ b/src/ZeroLog/LogEvent.cs @@ -367,6 +367,13 @@ private void AppendArgumentToStringBufferUnformatted(StringBuffer stringBuffer, enumArg->AppendTo(stringBuffer); break; + case ArgumentType.Unmanaged: + var unmanagedArgHeader = (UnmanagedArgHeader*)dataPointer; + dataPointer += sizeof(UnmanagedArgHeader); + unmanagedArgHeader->AppendUnformattedTo(stringBuffer, dataPointer); + dataPointer += unmanagedArgHeader->Size; + break; + case ArgumentType.Null: stringBuffer.Append(LogManager.Config.NullDisplayString); break; diff --git a/src/ZeroLog/UnmanagedArgHeader.cs b/src/ZeroLog/UnmanagedArgHeader.cs index ef1258a3..8fa6e9a2 100644 --- a/src/ZeroLog/UnmanagedArgHeader.cs +++ b/src/ZeroLog/UnmanagedArgHeader.cs @@ -25,18 +25,18 @@ public void AppendTo(StringBuffer stringBuffer, byte* valuePtr, StringView forma { if (!UnmanagedCache.TryGetFormatter(_typeHandle, out var formatter)) { - AppendUnregistered(stringBuffer, valuePtr, _typeSize); + AppendUnformattedTo(stringBuffer, valuePtr); return; } formatter(stringBuffer, valuePtr, format); } - private static void AppendUnregistered(StringBuffer buffer, byte* valuePtr, int size) + public void AppendUnformattedTo(StringBuffer stringBuffer, byte* valuePtr) { - buffer.Append("Unmanaged(0x"); - HexUtils.AppendValueAsHex(buffer, valuePtr, size); - buffer.Append(")"); + stringBuffer.Append("Unmanaged(0x"); + HexUtils.AppendValueAsHex(stringBuffer, valuePtr, _typeSize); + stringBuffer.Append(")"); } } }