diff --git a/src/NLog.Extensions.Logging/LayoutRenderers/ActivityTraceLayoutRenderer.cs b/src/NLog.Extensions.Logging/LayoutRenderers/ActivityTraceLayoutRenderer.cs new file mode 100644 index 00000000..6d2e9a07 --- /dev/null +++ b/src/NLog.Extensions.Logging/LayoutRenderers/ActivityTraceLayoutRenderer.cs @@ -0,0 +1,143 @@ +#if NETCOREAPP3_0 + +using System; +using System.Collections.Generic; +using System.Text; +using NLog.Config; +using NLog.LayoutRenderers; + +namespace NLog.Extensions.Logging +{ + /// + /// Layout renderer that can render properties from + /// + [LayoutRenderer("activity")] + [ThreadSafe] + public sealed class ActivityTraceLayoutRenderer : LayoutRenderer + { + private static readonly string EmptySpanId = default(System.Diagnostics.ActivitySpanId).ToString(); + private static readonly string EmptyTraceId = default(System.Diagnostics.ActivityTraceId).ToString(); + + /// + /// Gets or sets the property to retrieve. + /// + public ActivityTraceProperty Property { get; set; } = ActivityTraceProperty.Id; + + /// + /// Single item to extract from or + /// + public string Item { get; set; } + + /// + /// Control output formating of selected property (if supported) + /// + public string Format { get; set; } + + /// + protected override void Append(StringBuilder builder, LogEventInfo logEvent) + { + var activity = System.Diagnostics.Activity.Current; + if (activity == null) + return; + + if ((Property == ActivityTraceProperty.Baggage || Property == ActivityTraceProperty.Tags) && string.IsNullOrEmpty(Item)) + { + var collection = Property == ActivityTraceProperty.Baggage ? activity.Baggage : activity.Tags; + if (Format == "@") + { + RenderStringDictionaryJson(collection, builder); + } + else + { + RenderStringDictionaryFlat(collection, builder); + } + } + else + { + var value = GetValue(activity); + builder.Append(value); + } + } + + private string GetValue(System.Diagnostics.Activity activity) + { + switch (Property) + { + case ActivityTraceProperty.Id: return activity.Id; + case ActivityTraceProperty.TraceId: return CoalesceTraceId(activity.TraceId.ToString()); + case ActivityTraceProperty.SpanId: return CoalesceSpanId(activity.SpanId.ToString()); + case ActivityTraceProperty.OperationName: return activity.OperationName; + case ActivityTraceProperty.StartTimeUtc:return activity.StartTimeUtc > DateTime.MinValue ? activity.StartTimeUtc.ToString(Format) : string.Empty; + case ActivityTraceProperty.Duration: return activity.StartTimeUtc > DateTime.MinValue ? activity.Duration.ToString(Format) : string.Empty; + case ActivityTraceProperty.ParentId: return activity.ParentId; + case ActivityTraceProperty.ParentSpanId: return CoalesceSpanId(activity.ParentSpanId.ToString()); + case ActivityTraceProperty.RootId: return activity.RootId; + case ActivityTraceProperty.TraceState: return activity.TraceStateString; + case ActivityTraceProperty.ActivityTraceFlags: return activity.ActivityTraceFlags == System.Diagnostics.ActivityTraceFlags.None && string.IsNullOrEmpty(Format) ? string.Empty : activity.ActivityTraceFlags.ToString(Format); + case ActivityTraceProperty.Baggage: return GetCollectionItem(Item, activity.Baggage); + case ActivityTraceProperty.Tags: return GetCollectionItem(Item, activity.Tags); + default: return string.Empty; + } + } + + private static void RenderStringDictionaryFlat(IEnumerable> collection, StringBuilder builder) + { + var firstItem = true; + foreach (var keyValue in collection) + { + if (!firstItem) + builder.Append(","); + firstItem = false; + builder.Append(keyValue.Key); + builder.Append("="); + builder.Append(keyValue.Value); + } + } + + private static void RenderStringDictionaryJson(IEnumerable> collection, StringBuilder builder) + { + var firstItem = true; + foreach (var keyValue in collection) + { + if (firstItem) + builder.Append("{ "); + else + builder.Append(", "); + firstItem = false; + builder.Append("\""); + builder.Append(keyValue.Key); + builder.Append("\": \""); + builder.Append(keyValue.Value); + builder.Append("\""); + } + if (!firstItem) + builder.Append(" }"); + } + + private static string GetCollectionItem(string item, IEnumerable> collection) + { + foreach (var keyValue in collection) + if (item.Equals(keyValue.Key, StringComparison.OrdinalIgnoreCase)) + return keyValue.Value; + return string.Empty; + } + + private string CoalesceTraceId(string traceId) + { + if (EmptyTraceId == traceId) + return string.Empty; + else + return traceId; + } + + private string CoalesceSpanId(string spanId) + { + if (EmptySpanId == spanId) + return string.Empty; + else + return spanId; + } + } +} + +#endif \ No newline at end of file diff --git a/src/NLog.Extensions.Logging/LayoutRenderers/ActivityTraceProperty.cs b/src/NLog.Extensions.Logging/LayoutRenderers/ActivityTraceProperty.cs new file mode 100644 index 00000000..a34fe691 --- /dev/null +++ b/src/NLog.Extensions.Logging/LayoutRenderers/ActivityTraceProperty.cs @@ -0,0 +1,65 @@ +#if NETCOREAPP3_0 + +namespace NLog.Extensions.Logging +{ + /// + /// Properties from available for + /// + public enum ActivityTraceProperty + { + /// + /// Identifier that is specific to a particular request. + /// + Id, + /// + /// TraceId part of the + /// + TraceId, + /// + /// SPAN part of the + /// + SpanId, + /// + /// Operation name. + /// + OperationName, + /// + /// Time when the operation started. + /// + StartTimeUtc, + /// + /// Duration of the operation. + /// + Duration, + /// + /// Collection of key/value pairs that are passed to children of this Activity. + /// + Baggage, + /// + /// Collection of key/value pairs that are NOT passed to children of this Activity + /// + Tags, + /// + /// Activity's Parent ID. + /// + ParentId, + /// + /// Activity's Parent SpanID. + /// + ParentSpanId, + /// + /// Root ID of this Activity. + /// + RootId, + /// + /// W3C tracestate header. + /// + TraceState, + /// + /// for activity (defined by the W3C ID specification) + /// + ActivityTraceFlags, + } +} + +#endif \ No newline at end of file diff --git a/test/NLog.Extensions.Logging.Tests/ActivityTraceLayoutRendererTests.cs b/test/NLog.Extensions.Logging.Tests/ActivityTraceLayoutRendererTests.cs new file mode 100644 index 00000000..7e604c83 --- /dev/null +++ b/test/NLog.Extensions.Logging.Tests/ActivityTraceLayoutRendererTests.cs @@ -0,0 +1,233 @@ +#if NETCOREAPP3_0 + +using System; +using Xunit; + +namespace NLog.Extensions.Logging.Tests +{ + public class ActivityTraceLayoutRendererTests + { + [Fact] + public void TestAllPropertiesWhenActivityNull() + { + bool orgThrowExceptions = LogManager.ThrowExceptions; + + try + { + LogManager.ThrowExceptions = true; + System.Diagnostics.Activity.Current = null; + + var logEvent = LogEventInfo.CreateNullEvent(); + + foreach (ActivityTraceProperty property in Enum.GetValues(typeof(ActivityTraceProperty))) + { + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = property; + var result = layoutRenderer.Render(logEvent); + Assert.True(string.IsNullOrEmpty(result)); + } + } + finally + { + LogManager.ThrowExceptions = orgThrowExceptions; + } + } + + [Theory] + [InlineData(ActivityTraceProperty.Id, false)] // Id will never be empty + [InlineData(ActivityTraceProperty.TraceId, true)] + [InlineData(ActivityTraceProperty.OperationName, true)] + [InlineData(ActivityTraceProperty.StartTimeUtc, true)] + [InlineData(ActivityTraceProperty.Duration, true)] + [InlineData(ActivityTraceProperty.Baggage, true)] + [InlineData(ActivityTraceProperty.Tags, true)] + [InlineData(ActivityTraceProperty.ParentId, true)] + [InlineData(ActivityTraceProperty.ParentSpanId, true)] + [InlineData(ActivityTraceProperty.RootId, false)] // Will fallback to Id + [InlineData(ActivityTraceProperty.TraceState, true)] + [InlineData(ActivityTraceProperty.ActivityTraceFlags, true)] + public void TestAllPropertiesWhenActivityEmpty(ActivityTraceProperty property, bool empty) + { + bool orgThrowExceptions = LogManager.ThrowExceptions; + + try + { + LogManager.ThrowExceptions = true; + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity(null).Start(); + System.Diagnostics.Activity.Current.SetStartTime(new DateTime(0, DateTimeKind.Utc)); + + var logEvent = LogEventInfo.CreateNullEvent(); + + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = property; + var result = layoutRenderer.Render(logEvent); + Assert.True(string.IsNullOrEmpty(result) == empty); + } + finally + { + LogManager.ThrowExceptions = orgThrowExceptions; + } + } + + [Theory] + [InlineData(ActivityTraceProperty.Id, null, null)] // Id will never be empty + [InlineData(ActivityTraceProperty.TraceId, null, "")] + [InlineData(ActivityTraceProperty.OperationName, null, "MyOperation")] + [InlineData(ActivityTraceProperty.StartTimeUtc, "u", "0001-01-01 00:00:00Z")] + [InlineData(ActivityTraceProperty.Duration, null, "00:00:00")] + [InlineData(ActivityTraceProperty.Baggage, null, "")] + [InlineData(ActivityTraceProperty.Tags, null, "")] + [InlineData(ActivityTraceProperty.ParentId, null, "")] + [InlineData(ActivityTraceProperty.ParentSpanId, null, "")] + [InlineData(ActivityTraceProperty.RootId, null, null)] // Will fallback to Id + [InlineData(ActivityTraceProperty.TraceState, null, "")] + [InlineData(ActivityTraceProperty.ActivityTraceFlags, null, "")] + public void TestAllPropertiesWhenActivityRunning(ActivityTraceProperty property, string format, string output) + { + bool orgThrowExceptions = LogManager.ThrowExceptions; + + try + { + DateTime startedTime = new DateTime(1, DateTimeKind.Utc); + + LogManager.ThrowExceptions = true; + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start(); + System.Diagnostics.Activity.Current.SetStartTime(startedTime); + + var logEvent = LogEventInfo.CreateNullEvent(); + + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = property; + layoutRenderer.Format = format; + var result = layoutRenderer.Render(logEvent); + if (output != null) + Assert.Equal(output, result); + } + finally + { + LogManager.ThrowExceptions = orgThrowExceptions; + } + } + + [Fact] + public void TestBaggageSingleItem() + { + // Arrange + var logEvent = LogEventInfo.CreateNullEvent(); + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = ActivityTraceProperty.Baggage; + + // Act + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start().AddBaggage("myitem1", "myvalue1"); + var result = layoutRenderer.Render(logEvent); + + // Assert + Assert.Equal("myitem1=myvalue1", result); + } + + [Fact] + public void TestBaggageSingleItemJson() + { + // Arrange + var logEvent = LogEventInfo.CreateNullEvent(); + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = ActivityTraceProperty.Baggage; + layoutRenderer.Format = "@"; + + // Act + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start().AddBaggage("myitem1", "myvalue1"); + var result = layoutRenderer.Render(logEvent); + + // Assert + Assert.Equal("{ \"myitem1\": \"myvalue1\" }", result); + } + + [Fact] + public void TestBaggageDoubleItem() + { + // Arrange + var logEvent = LogEventInfo.CreateNullEvent(); + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = ActivityTraceProperty.Baggage; + + // Act + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start().AddBaggage("myitem1", "myvalue1").AddBaggage("myitem2", "myvalue2"); + var result = layoutRenderer.Render(logEvent); + + // Assert + Assert.Contains("myitem1=myvalue1", result); + Assert.Contains("myitem2=myvalue2", result); + } + + [Fact] + public void TestBaggageDoubleItemJson() + { + // Arrange + var logEvent = LogEventInfo.CreateNullEvent(); + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = ActivityTraceProperty.Baggage; + layoutRenderer.Format = "@"; + + // Act + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start().AddBaggage("myitem1", "myvalue1").AddBaggage("myitem2", "myvalue2"); + var result = layoutRenderer.Render(logEvent); + + var jsonElement = (System.Text.Json.JsonElement)System.Text.Json.JsonSerializer.Deserialize(result, typeof(object)); + Assert.Equal("myvalue1", jsonElement.GetProperty("myitem1").GetString()); + Assert.Equal("myvalue2", jsonElement.GetProperty("myitem2").GetString()); + } + + [Fact] + public void TestTagsSingleItem() + { + // Arrange + var logEvent = LogEventInfo.CreateNullEvent(); + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = ActivityTraceProperty.Tags; + + // Act + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start().AddTag("myitem1", "myvalue1"); + var result = layoutRenderer.Render(logEvent); + + // Assert + Assert.Equal("myitem1=myvalue1", result); + } + + [Fact] + public void TestTagsDoubleItem() + { + // Arrange + var logEvent = LogEventInfo.CreateNullEvent(); + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = ActivityTraceProperty.Tags; + + // Act + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start().AddTag("myitem1", "myvalue1").AddTag("myitem2", "myvalue2"); + var result = layoutRenderer.Render(logEvent); + + // Assert + Assert.Contains("myitem1=myvalue1", result); + Assert.Contains("myitem2=myvalue2", result); + } + + [Fact] + public void TestTagsDoubleItemJson() + { + // Arrange + var logEvent = LogEventInfo.CreateNullEvent(); + ActivityTraceLayoutRenderer layoutRenderer = new ActivityTraceLayoutRenderer(); + layoutRenderer.Property = ActivityTraceProperty.Tags; + layoutRenderer.Format = "@"; + + // Act + System.Diagnostics.Activity.Current = new System.Diagnostics.Activity("MyOperation").Start().AddTag("myitem1", "myvalue1").AddTag("myitem2", "myvalue2"); + var result = layoutRenderer.Render(logEvent); + + var jsonElement = (System.Text.Json.JsonElement)System.Text.Json.JsonSerializer.Deserialize(result, typeof(object)); + Assert.Equal("myvalue1", jsonElement.GetProperty("myitem1").GetString()); + Assert.Equal("myvalue2", jsonElement.GetProperty("myitem2").GetString()); + } + } +} + +#endif \ No newline at end of file