diff --git a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs index be23470c91d..6a794e28d35 100644 --- a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs +++ b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs @@ -40,9 +40,9 @@ public override ExportResult Export(in Batch batch) this.WriteLine($"{"LogRecord.CategoryName:".PadRight(RightPaddingLength)}{logRecord.CategoryName}"); this.WriteLine($"{"LogRecord.LogLevel:".PadRight(RightPaddingLength)}{logRecord.LogLevel}"); this.WriteLine($"{"LogRecord.TraceFlags:".PadRight(RightPaddingLength)}{logRecord.TraceFlags}"); - if (logRecord.Message != null) + if (logRecord.FormattedMessage != null) { - this.WriteLine($"{"LogRecord.Message:".PadRight(RightPaddingLength)}{logRecord.Message}"); + this.WriteLine($"{"LogRecord.FormattedMessage:".PadRight(RightPaddingLength)}{logRecord.FormattedMessage}"); } if (logRecord.State != null) diff --git a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt index 8af801f0f31..cf073b25a0c 100644 --- a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt @@ -1,8 +1,8 @@ OpenTelemetry.Logs.LogRecord.ForEachScope(System.Action callback, TState state) -> void -OpenTelemetry.Logs.LogRecord.Message.get -> string +OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> -OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.get -> bool -OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.set -> void +OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.get -> bool +OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.ParseStateValues.get -> bool diff --git a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index 8af801f0f31..cf073b25a0c 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -1,8 +1,8 @@ OpenTelemetry.Logs.LogRecord.ForEachScope(System.Action callback, TState state) -> void -OpenTelemetry.Logs.LogRecord.Message.get -> string +OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> -OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.get -> bool -OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.set -> void +OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.get -> bool +OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.ParseStateValues.get -> bool diff --git a/src/OpenTelemetry/CHANGELOG.md b/src/OpenTelemetry/CHANGELOG.md index 140f163f6de..c3fc8d255a2 100644 --- a/src/OpenTelemetry/CHANGELOG.md +++ b/src/OpenTelemetry/CHANGELOG.md @@ -43,6 +43,12 @@ please check the latest changes `ParentBasedSampler` will no longer explicitly consider Activity links. ([#1851](https://github.com/open-telemetry/opentelemetry-dotnet/pull/1851)) +* Added `IncludeScopes`, `IncludeFormattedMessage`, & `ParseStateValues` on + `OpenTelemetryLoggerOptions`. Added `FormattedMessage`, `StateValues`, & + `ForEachScope` on `LogRecord`. + ([#1869](https://github.com/open-telemetry/opentelemetry-dotnet/pull/1869) & + [#1883](https://github.com/open-telemetry/opentelemetry-dotnet/pull/1883)) + ## 1.0.1 Released 2021-Feb-10 diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index d054bf4193c..780f943ec0d 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -35,7 +35,7 @@ internal LogRecord( string categoryName, LogLevel logLevel, EventId eventId, - string message, + string formattedMessage, object state, Exception exception, IReadOnlyList> stateValues) @@ -55,7 +55,7 @@ internal LogRecord( this.CategoryName = categoryName; this.LogLevel = logLevel; this.EventId = eventId; - this.Message = message; + this.FormattedMessage = formattedMessage; this.State = state; this.StateValues = stateValues; this.Exception = exception; @@ -77,7 +77,7 @@ internal LogRecord( public EventId EventId { get; } - public string Message { get; } + public string FormattedMessage { get; } public object State { get; } diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs index fe8815da318..f1dcea4f697 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs @@ -17,7 +17,6 @@ #if NET461 || NETSTANDARD2_0 using System; using System.Collections.Generic; -using System.Reflection.Emit; using System.Runtime.CompilerServices; using Microsoft.Extensions.Logging; @@ -38,7 +37,8 @@ internal OpenTelemetryLogger(string categoryName, OpenTelemetryLoggerProvider pr public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) { - if (!this.IsEnabled(logLevel) || Sdk.SuppressInstrumentation) + if (!this.IsEnabled(logLevel) + || Sdk.SuppressInstrumentation) { return; } @@ -54,7 +54,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except this.categoryName, logLevel, eventId, - options.IncludeMessage ? formatter(state, exception) : null, + options.IncludeFormattedMessage ? formatter(state, exception) : null, options.ParseStateValues ? null : (object)state, exception, options.ParseStateValues ? this.ParseState(state) : null); @@ -73,9 +73,9 @@ public bool IsEnabled(LogLevel logLevel) private IReadOnlyList> ParseState(TState state) { - if (state is IReadOnlyList>) + if (state is IReadOnlyList> stateList) { - return StateValueListParser.ParseStateFunc(state); + return stateList; } else if (state is IEnumerable> stateValues) { @@ -89,107 +89,6 @@ private IReadOnlyList> ParseState(TState st }; } } - - private static class StateValueListParser - { - static StateValueListParser() - { - /* The code below is building a dynamic method to do this... - - int count = state.Count; - - List> stateValues = new List>(count); - - for (int i = 0; i < count; i++) - { - stateValues.Add(state[i]); - } - - return stateValues; - - ...so we don't box structs or allocate an enumerator. */ - - var stateType = typeof(TState); - var listType = typeof(List>); - var readOnlyListType = typeof(IReadOnlyList>); - - var dynamicMethod = new DynamicMethod( - nameof(StateValueListParser), - readOnlyListType, - new[] { stateType }, - typeof(StateValueListParser).Module, - skipVisibility: true); - - var generator = dynamicMethod.GetILGenerator(); - - var testLabel = generator.DefineLabel(); - var writeItemLabel = generator.DefineLabel(); - - generator.DeclareLocal(typeof(int)); // count - generator.DeclareLocal(listType); // list - generator.DeclareLocal(typeof(int)); // i - - if (stateType.IsValueType) - { - generator.Emit(OpCodes.Ldarga_S, 0); // state - generator.Emit(OpCodes.Call, stateType.GetProperty("Count").GetMethod); - } - else - { - generator.Emit(OpCodes.Ldarg_0); // state - generator.Emit(OpCodes.Callvirt, typeof(IReadOnlyCollection>).GetProperty("Count").GetMethod); - } - - generator.Emit(OpCodes.Stloc_0); // count = state.Count - generator.Emit(OpCodes.Ldloc_0); - generator.Emit(OpCodes.Newobj, listType.GetConstructor(new Type[] { typeof(int) })); - generator.Emit(OpCodes.Stloc_1); // list = new List(count) - - generator.Emit(OpCodes.Ldc_I4_0); - generator.Emit(OpCodes.Stloc_2); // i = 0 - - generator.Emit(OpCodes.Br_S, testLabel); - generator.MarkLabel(writeItemLabel); - generator.Emit(OpCodes.Ldloc_1); // list - if (stateType.IsValueType) - { - generator.Emit(OpCodes.Ldarga_S, 0); // state - } - else - { - generator.Emit(OpCodes.Ldarg_0); // state - } - - generator.Emit(OpCodes.Ldloc_2); // i - if (stateType.IsValueType) - { - generator.Emit(OpCodes.Call, stateType.GetProperty("Item").GetMethod); - } - else - { - generator.Emit(OpCodes.Callvirt, readOnlyListType.GetProperty("Item").GetMethod); - } - - generator.Emit(OpCodes.Callvirt, listType.GetMethod("Add", new Type[] { typeof(KeyValuePair) })); // list.Add(state[i]) - - generator.Emit(OpCodes.Ldloc_2); // i - generator.Emit(OpCodes.Ldc_I4_1); - generator.Emit(OpCodes.Add); // i++ - generator.Emit(OpCodes.Stloc_2); - - generator.MarkLabel(testLabel); - generator.Emit(OpCodes.Ldloc_2); // i - generator.Emit(OpCodes.Ldloc_0); // count - generator.Emit(OpCodes.Blt_S, writeItemLabel); - - generator.Emit(OpCodes.Ldloc_1); // list - generator.Emit(OpCodes.Ret); - - ParseStateFunc = (Func>>)dynamicMethod.CreateDelegate(typeof(Func>>)); - } - - public static Func>> ParseStateFunc { get; } - } } } #endif diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLoggerOptions.cs b/src/OpenTelemetry/Logs/OpenTelemetryLoggerOptions.cs index 0d9b3b5e328..6eaf780d9b9 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLoggerOptions.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLoggerOptions.cs @@ -25,18 +25,29 @@ public class OpenTelemetryLoggerOptions internal readonly List> Processors = new List>(); /// - /// Gets or sets a value indicating whether or not log scopes should be included on generated s. Default value: False. + /// Gets or sets a value indicating whether or not log scopes should be + /// included on generated s. Default value: + /// False. /// public bool IncludeScopes { get; set; } /// - /// Gets or sets a value indicating whether or not log message should be included on generated s. Default value: False. + /// Gets or sets a value indicating whether or not formatted log message + /// should be included on generated s. Default + /// value: False. /// - public bool IncludeMessage { get; set; } + public bool IncludeFormattedMessage { get; set; } /// - /// Gets or sets a value indicating whether or not log state should be parsed into on generated s. Default value: False. + /// Gets or sets a value indicating whether or not log state should be + /// parsed into on generated s. Default value: False. /// + /// + /// Note: When is set to will always be . + /// public bool ParseStateValues { get; set; } /// diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs index 3d890ec849a..c35a6a5a3b7 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs @@ -19,6 +19,7 @@ using Microsoft.Extensions.DependencyInjection; #endif using System; +using System.Collections; using System.Collections.Generic; using System.Diagnostics; using System.Globalization; @@ -42,6 +43,7 @@ public class LogRecordTest : IDisposable #endif private readonly BaseExportProcessor processor; private readonly BaseExporter exporter; + private OpenTelemetryLoggerOptions options; public LogRecordTest() { @@ -53,8 +55,12 @@ public LogRecordTest() this.loggerFactory = LoggerFactory.Create(builder => #endif { - builder.AddOpenTelemetry(options => options - .AddProcessor(this.processor)); + builder.AddOpenTelemetry(options => + { + this.options = options; + options + .AddProcessor(this.processor); + }); builder.AddFilter(typeof(LogRecordTest).FullName, LogLevel.Trace); }); @@ -309,6 +315,223 @@ public void CheckTraceIdForLogWithinActivityMarkedAsRecordAndSample() Assert.Equal(currentActivity.ActivityTraceFlags, logRecord.TraceFlags); } + [Fact] + public void IncludeFormattedMessageTest() + { + this.logger.LogInformation("OpenTelemetry!"); + var logRecord = this.exportedItems[0]; + Assert.Null(logRecord.FormattedMessage); + + this.options.IncludeFormattedMessage = true; + try + { + this.logger.LogInformation("OpenTelemetry!"); + logRecord = this.exportedItems[1]; + Assert.Equal("OpenTelemetry!", logRecord.FormattedMessage); + + this.logger.LogInformation("OpenTelemetry {Greeting} {Subject}!", "Hello", "World"); + logRecord = this.exportedItems[2]; + Assert.Equal("OpenTelemetry Hello World!", logRecord.FormattedMessage); + } + finally + { + this.options.IncludeFormattedMessage = false; + } + } + + [Fact] + public void IncludeScopesTest() + { + using var scope = this.logger.BeginScope("string_scope"); + + this.logger.LogInformation("OpenTelemetry!"); + var logRecord = this.exportedItems[0]; + + List scopes = new List(); + logRecord.ForEachScope((scope, state) => scopes.Add(scope), null); + Assert.Empty(scopes); + + this.options.IncludeScopes = true; + try + { + this.logger.LogInformation("OpenTelemetry!"); + logRecord = this.exportedItems[1]; + + logRecord.ForEachScope((scope, state) => scopes.Add(scope), null); + Assert.Single(scopes); + Assert.Equal("string_scope", scopes[0]); + + scopes.Clear(); + + using var scope2 = this.logger.BeginScope(2021); + + this.logger.LogInformation("OpenTelemetry!"); + logRecord = this.exportedItems[2]; + + logRecord.ForEachScope((scope, state) => scopes.Add(scope), null); + Assert.Equal(2, scopes.Count); + Assert.Equal("string_scope", scopes[0]); + Assert.Equal(2021, scopes[1]); + } + finally + { + this.options.IncludeScopes = false; + } + } + + [Fact] + public void ParseStateValuesUsingStandardExtensionsTest() + { + // Tests state parsing with standard extensions. + + this.logger.LogInformation("{Product} {Year}!", "OpenTelemetry", 2021); + var logRecord = this.exportedItems[0]; + + Assert.NotNull(logRecord.State); + Assert.Null(logRecord.StateValues); + + this.options.ParseStateValues = true; + try + { + var complex = new { Property = "Value" }; + + this.logger.LogInformation("{Product} {Year} {Complex}!", "OpenTelemetry", 2021, complex); + logRecord = this.exportedItems[1]; + + Assert.Null(logRecord.State); + Assert.NotNull(logRecord.StateValues); + Assert.Equal(4, logRecord.StateValues.Count); + Assert.Equal(new KeyValuePair("Product", "OpenTelemetry"), logRecord.StateValues[0]); + Assert.Equal(new KeyValuePair("Year", 2021), logRecord.StateValues[1]); + Assert.Equal(new KeyValuePair("{OriginalFormat}", "{Product} {Year} {Complex}!"), logRecord.StateValues[3]); + + KeyValuePair actualComplex = logRecord.StateValues[2]; + Assert.Equal("Complex", actualComplex.Key); + Assert.Same(complex, actualComplex.Value); + } + finally + { + this.options.ParseStateValues = false; + } + } + + [Fact] + public void ParseStateValuesUsingStructTest() + { + // Tests struct IReadOnlyList> parse path. + + this.options.ParseStateValues = true; + try + { + this.logger.Log( + LogLevel.Information, + 0, + new StructState(new KeyValuePair("Key1", "Value1")), + null, + (s, e) => "OpenTelemetry!"); + var logRecord = this.exportedItems[0]; + + Assert.Null(logRecord.State); + Assert.NotNull(logRecord.StateValues); + Assert.Equal(1, logRecord.StateValues.Count); + Assert.Equal(new KeyValuePair("Key1", "Value1"), logRecord.StateValues[0]); + } + finally + { + this.options.ParseStateValues = false; + } + } + + [Fact] + public void ParseStateValuesUsingListTest() + { + // Tests ref IReadOnlyList> parse path. + + this.options.ParseStateValues = true; + try + { + this.logger.Log( + LogLevel.Information, + 0, + new List> { new KeyValuePair("Key1", "Value1") }, + null, + (s, e) => "OpenTelemetry!"); + var logRecord = this.exportedItems[0]; + + Assert.Null(logRecord.State); + Assert.NotNull(logRecord.StateValues); + Assert.Equal(1, logRecord.StateValues.Count); + Assert.Equal(new KeyValuePair("Key1", "Value1"), logRecord.StateValues[0]); + } + finally + { + this.options.ParseStateValues = false; + } + } + + [Fact] + public void ParseStateValuesUsingIEnumerableTest() + { + // Tests IEnumerable> parse path. + + this.options.ParseStateValues = true; + try + { + this.logger.Log( + LogLevel.Information, + 0, + new ListState(new KeyValuePair("Key1", "Value1")), + null, + (s, e) => "OpenTelemetry!"); + var logRecord = this.exportedItems[0]; + + Assert.Null(logRecord.State); + Assert.NotNull(logRecord.StateValues); + Assert.Equal(1, logRecord.StateValues.Count); + Assert.Equal(new KeyValuePair("Key1", "Value1"), logRecord.StateValues[0]); + } + finally + { + this.options.ParseStateValues = false; + } + } + + [Fact] + public void ParseStateValuesUsingCustomTest() + { + // Tests unknown state parse path. + + this.options.ParseStateValues = true; + try + { + CustomState state = new CustomState + { + Property = "Value", + }; + + this.logger.Log( + LogLevel.Information, + 0, + state, + null, + (s, e) => "OpenTelemetry!"); + var logRecord = this.exportedItems[0]; + + Assert.Null(logRecord.State); + Assert.NotNull(logRecord.StateValues); + Assert.Equal(1, logRecord.StateValues.Count); + + KeyValuePair actualState = logRecord.StateValues[0]; + + Assert.Equal(string.Empty, actualState.Key); + Assert.Same(state, actualState.Value); + } + finally + { + this.options.ParseStateValues = false; + } + } + public void Dispose() { #if NETCOREAPP2_1 @@ -324,6 +547,55 @@ internal struct Food public double Price { get; set; } } + + private struct StructState : IReadOnlyList> + { + private readonly List> list; + + public StructState(params KeyValuePair[] items) + { + this.list = new List>(items); + } + + public int Count => this.list.Count; + + public KeyValuePair this[int index] => this.list[index]; + + public IEnumerator> GetEnumerator() + { + return this.list.GetEnumerator(); + } + + IEnumerator IEnumerable.GetEnumerator() + { + return this.list.GetEnumerator(); + } + } + + private class ListState : IEnumerable> + { + private readonly List> list; + + public ListState(params KeyValuePair[] items) + { + this.list = new List>(items); + } + + public IEnumerator> GetEnumerator() + { + return this.list.GetEnumerator(); + } + + IEnumerator IEnumerable.GetEnumerator() + { + return this.list.GetEnumerator(); + } + } + + private class CustomState + { + public string Property { get; set; } + } } } #endif