Ported logging changes from PR 1833. (#1869)

Co-authored-by: Cijo Thomas <[email protected]>

src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt

@@ -1,3 +1,12 @@
+OpenTelemetry.Logs.LogRecord.ForEachScope<TState>(System.Action<object, TState> callback, TState state) -> void
+OpenTelemetry.Logs.LogRecord.Message.get -> string
+OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList<System.Collections.Generic.KeyValuePair<string, object>>
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.get -> bool
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.set -> void
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.set -> void
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.ParseStateValues.get -> bool
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.ParseStateValues.set -> void
 OpenTelemetry.Trace.ParentBasedSampler.ParentBasedSampler(OpenTelemetry.Trace.Sampler rootSampler, OpenTelemetry.Trace.Sampler remoteParentSampled = null, OpenTelemetry.Trace.Sampler remoteParentNotSampled = null, OpenTelemetry.Trace.Sampler localParentSampled = null, OpenTelemetry.Trace.Sampler localParentNotSampled = null) -> void
 OpenTelemetry.Trace.TracerProviderOptions
 OpenTelemetry.Trace.TracerProviderOptions.SetErrorStatusOnException.get -> bool

src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt

@@ -1,3 +1,12 @@
+OpenTelemetry.Logs.LogRecord.ForEachScope<TState>(System.Action<object, TState> callback, TState state) -> void
+OpenTelemetry.Logs.LogRecord.Message.get -> string
+OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList<System.Collections.Generic.KeyValuePair<string, object>>
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.get -> bool
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeMessage.set -> void
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.set -> void
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.ParseStateValues.get -> bool
+OpenTelemetry.Logs.OpenTelemetryLoggerOptions.ParseStateValues.set -> void
 OpenTelemetry.Trace.ParentBasedSampler.ParentBasedSampler(OpenTelemetry.Trace.Sampler rootSampler, OpenTelemetry.Trace.Sampler remoteParentSampled = null, OpenTelemetry.Trace.Sampler remoteParentNotSampled = null, OpenTelemetry.Trace.Sampler localParentSampled = null, OpenTelemetry.Trace.Sampler localParentNotSampled = null) -> void
 OpenTelemetry.Trace.TracerProviderOptions
 OpenTelemetry.Trace.TracerProviderOptions.SetErrorStatusOnException.get -> bool

src/OpenTelemetry/Logs/LogRecord.cs

@@ -16,6 +16,7 @@
 
 #if NET461 || NETSTANDARD2_0
 using System;
+using System.Collections.Generic;
 using System.Diagnostics;
 using Microsoft.Extensions.Logging;
 
@@ -26,9 +27,20 @@ namespace OpenTelemetry.Logs
     /// </summary>
     public sealed class LogRecord
     {
-        internal LogRecord(DateTime timestamp, string categoryName, LogLevel logLevel, EventId eventId, object state, Exception exception)
+        private readonly IExternalScopeProvider scopeProvider;
+
+        internal LogRecord(
+            IExternalScopeProvider scopeProvider,
+            DateTime timestamp,
+            string categoryName,
+            LogLevel logLevel,
+            EventId eventId,
+            string message,
+            object state,
+            Exception exception,
+            IReadOnlyList<KeyValuePair<string, object>> stateValues)
         {
-            this.Timestamp = timestamp;
+            this.scopeProvider = scopeProvider;
 
             var activity = Activity.Current;
             if (activity != null)
@@ -39,10 +51,13 @@ internal LogRecord(DateTime timestamp, string categoryName, LogLevel logLevel, E
                 this.TraceFlags = activity.ActivityTraceFlags;
             }
 
+            this.Timestamp = timestamp;
             this.CategoryName = categoryName;
             this.LogLevel = logLevel;
             this.EventId = eventId;
+            this.Message = message;
             this.State = state;
+            this.StateValues = stateValues;
             this.Exception = exception;
         }
 
@@ -62,9 +77,26 @@ internal LogRecord(DateTime timestamp, string categoryName, LogLevel logLevel, E
 
         public EventId EventId { get; }
 
+        public string Message { get; }
+
         public object State { get; }
 
+        public IReadOnlyList<KeyValuePair<string, object>> StateValues { get; }
+
         public Exception Exception { get; }
+
+        /// <summary>
+        /// Executes callback for each currently active scope objects in order
+        /// of creation. All callbacks are guaranteed to be called inline from
+        /// this method.
+        /// </summary>
+        /// <typeparam name="TState">State.</typeparam>
+        /// <param name="callback">The callback to be executed for every scope object.</param>
+        /// <param name="state">The state object to be passed into the callback.</param>
+        public void ForEachScope<TState>(Action<object, TState> callback, TState state)
+        {
+            this.scopeProvider?.ForEachScope(callback, state);
+        }
     }
 }
 #endif

src/OpenTelemetry/Logs/OpenTelemetryLogger.cs

@@ -16,8 +16,9 @@
 
 #if NET461 || NETSTANDARD2_0
 using System;
+using System.Collections.Generic;
+using System.Reflection.Emit;
 using System.Runtime.CompilerServices;
-using System.Threading;
 using Microsoft.Extensions.Logging;
 
 namespace OpenTelemetry.Logs
@@ -37,19 +38,29 @@ internal OpenTelemetryLogger(string categoryName, OpenTelemetryLoggerProvider pr
 
         public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
         {
-            if (!this.IsEnabled(logLevel))
+            if (!this.IsEnabled(logLevel) || Sdk.SuppressInstrumentation)
             {
                 return;
             }
 
-            if (Sdk.SuppressInstrumentation)
+            var processor = this.provider.Processor;
+            if (processor != null)
             {
-                return;
-            }
+                var options = this.provider.Options;
 
-            var record = new LogRecord(DateTime.UtcNow, this.categoryName, logLevel, eventId, state, exception);
+                var record = new LogRecord(
+                    options.IncludeScopes ? this.ScopeProvider : null,
+                    DateTime.UtcNow,
+                    this.categoryName,
+                    logLevel,
+                    eventId,
+                    options.IncludeMessage ? formatter(state, exception) : null,
+                    options.ParseStateValues ? null : (object)state,
+                    exception,
+                    options.ParseStateValues ? this.ParseState(state) : null);
 
-            this.provider.Processor?.OnEnd(record);
+                processor.OnEnd(record);
+            }
         }
 
         [MethodImpl(MethodImplOptions.AggressiveInlining)]
@@ -59,6 +70,126 @@ public bool IsEnabled(LogLevel logLevel)
         }
 
         public IDisposable BeginScope<TState>(TState state) => this.ScopeProvider?.Push(state) ?? null;
+
+        private IReadOnlyList<KeyValuePair<string, object>> ParseState<TState>(TState state)
+        {
+            if (state is IReadOnlyList<KeyValuePair<string, object>>)
+            {
+                return StateValueListParser<TState>.ParseStateFunc(state);
+            }
+            else if (state is IEnumerable<KeyValuePair<string, object>> stateValues)
+            {
+                return new List<KeyValuePair<string, object>>(stateValues);
+            }
+            else
+            {
+                return new List<KeyValuePair<string, object>>
+                {
+                    new KeyValuePair<string, object>(string.Empty, state),
+                };
+            }
+        }
+
+        private static class StateValueListParser<TState>
+        {
+            static StateValueListParser()
+            {
+                /* The code below is building a dynamic method to do this...
+
+                     int count = state.Count;
+
+                     List<KeyValuePair<string, object>> stateValues = new List<KeyValuePair<string, object>>(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<KeyValuePair<string, object>>);
+                var readOnlyListType = typeof(IReadOnlyList<KeyValuePair<string, object>>);
+
+                var dynamicMethod = new DynamicMethod(
+                    nameof(StateValueListParser<TState>),
+                    readOnlyListType,
+                    new[] { stateType },
+                    typeof(StateValueListParser<TState>).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<KeyValuePair<string, object>>).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<string, object>) })); // 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<TState, IReadOnlyList<KeyValuePair<string, object>>>)dynamicMethod.CreateDelegate(typeof(Func<TState, IReadOnlyList<KeyValuePair<string, object>>>));
+            }
+
+            public static Func<TState, IReadOnlyList<KeyValuePair<string, object>>> ParseStateFunc { get; }
+        }
     }
 }
 #endif

src/OpenTelemetry/Logs/OpenTelemetryLoggerOptions.cs

@@ -17,14 +17,28 @@
 #if NET461 || NETSTANDARD2_0
 using System;
 using System.Collections.Generic;
-using Microsoft.Extensions.Logging;
 
 namespace OpenTelemetry.Logs
 {
     public class OpenTelemetryLoggerOptions
     {
         internal readonly List<BaseProcessor<LogRecord>> Processors = new List<BaseProcessor<LogRecord>>();
 
+        /// <summary>
+        /// Gets or sets a value indicating whether or not log scopes should be included on generated <see cref="LogRecord"/>s. Default value: False.
+        /// </summary>
+        public bool IncludeScopes { get; set; }
+
+        /// <summary>
+        /// Gets or sets a value indicating whether or not log message should be included on generated <see cref="LogRecord"/>s. Default value: False.
+        /// </summary>
+        public bool IncludeMessage { get; set; }
+
+        /// <summary>
+        /// Gets or sets a value indicating whether or not log state should be parsed into <see cref="LogRecord.StateValues"/> on generated <see cref="LogRecord"/>s. Default value: False.
+        /// </summary>
+        public bool ParseStateValues { get; set; }
+
         /// <summary>
         /// Adds processor to the options.
         /// </summary>

src/OpenTelemetry/Logs/OpenTelemetryLoggerProvider.cs

@@ -16,7 +16,7 @@
 
 #if NET461 || NETSTANDARD2_0
 using System;
-using System.Collections.Generic;
+using System.Collections;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
 
@@ -25,9 +25,9 @@ namespace OpenTelemetry.Logs
     [ProviderAlias("OpenTelemetry")]
     public class OpenTelemetryLoggerProvider : ILoggerProvider, ISupportExternalScope
     {
+        internal readonly OpenTelemetryLoggerOptions Options;
         internal BaseProcessor<LogRecord> Processor;
-        private readonly OpenTelemetryLoggerOptions options;
-        private readonly IDictionary<string, ILogger> loggers;
+        private readonly Hashtable loggers = new Hashtable();
         private bool disposed;
         private IExternalScopeProvider scopeProvider;
 
@@ -45,49 +45,50 @@ public OpenTelemetryLoggerProvider(IOptionsMonitor<OpenTelemetryLoggerOptions> o
 
         internal OpenTelemetryLoggerProvider(OpenTelemetryLoggerOptions options)
         {
-            this.options = options ?? throw new ArgumentNullException(nameof(options));
-            this.loggers = new Dictionary<string, ILogger>(StringComparer.Ordinal);
+            this.Options = options ?? throw new ArgumentNullException(nameof(options));
 
             foreach (var processor in options.Processors)
             {
                 this.AddProcessor(processor);
             }
         }
 
-        internal IExternalScopeProvider ScopeProvider
+        void ISupportExternalScope.SetScopeProvider(IExternalScopeProvider scopeProvider)
         {
-            get
+            this.scopeProvider = scopeProvider;
+
+            lock (this.loggers)
             {
-                if (this.scopeProvider == null)
+                foreach (DictionaryEntry entry in this.loggers)
                 {
-                    this.scopeProvider = new LoggerExternalScopeProvider();
+                    if (entry.Value is OpenTelemetryLogger logger)
+                    {
+                        logger.ScopeProvider = scopeProvider;
+                    }
                 }
-
-                return this.scopeProvider;
             }
         }
 
-        void ISupportExternalScope.SetScopeProvider(IExternalScopeProvider scopeProvider)
-        {
-            // TODO: set existing loggers
-            this.scopeProvider = scopeProvider;
-        }
-
         public ILogger CreateLogger(string categoryName)
         {
-            lock (this.loggers)
+            if (!(this.loggers[categoryName] is OpenTelemetryLogger logger))
             {
-                ILogger logger;
-
-                if (this.loggers.TryGetValue(categoryName, out logger))
+                lock (this.loggers)
                 {
-                    return logger;
+                    logger = this.loggers[categoryName] as OpenTelemetryLogger;
+                    if (logger == null)
+                    {
+                        logger = new OpenTelemetryLogger(categoryName, this)
+                        {
+                            ScopeProvider = this.scopeProvider,
+                        };
+
+                        this.loggers[categoryName] = logger;
+                    }
                 }
-
-                logger = new OpenTelemetryLogger(categoryName, this);
-                this.loggers.Add(categoryName, logger);
-                return logger;
             }
+
+            return logger;
         }
 
         /// <inheritdoc/>