Skip to content

Commit

Permalink
Logs: Scopes, State, & FormattedMessage follow-up (#1883)
Browse files Browse the repository at this point in the history
* Code review, unit tests, and performance tweaks for logging changes.

* Fixed up ConsoleLogRecordExporter for renames.

* CHANGELOG update.
  • Loading branch information
CodeBlanch authored Mar 13, 2021
1 parent 41a3371 commit b021b63
Show file tree
Hide file tree
Showing 8 changed files with 311 additions and 123 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -40,9 +40,9 @@ public override ExportResult Export(in Batch<LogRecord> 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)
Expand Down
6 changes: 3 additions & 3 deletions src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt
Original file line number Diff line number Diff line change
@@ -1,8 +1,8 @@
OpenTelemetry.Logs.LogRecord.ForEachScope<TState>(System.Action<object, TState> 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<System.Collections.Generic.KeyValuePair<string, object>>
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
Expand Down
Original file line number Diff line number Diff line change
@@ -1,8 +1,8 @@
OpenTelemetry.Logs.LogRecord.ForEachScope<TState>(System.Action<object, TState> 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<System.Collections.Generic.KeyValuePair<string, object>>
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
Expand Down
6 changes: 6 additions & 0 deletions src/OpenTelemetry/CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
6 changes: 3 additions & 3 deletions src/OpenTelemetry/Logs/LogRecord.cs
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,7 @@ internal LogRecord(
string categoryName,
LogLevel logLevel,
EventId eventId,
string message,
string formattedMessage,
object state,
Exception exception,
IReadOnlyList<KeyValuePair<string, object>> stateValues)
Expand All @@ -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;
Expand All @@ -77,7 +77,7 @@ internal LogRecord(

public EventId EventId { get; }

public string Message { get; }
public string FormattedMessage { get; }

public object State { get; }

Expand Down
111 changes: 5 additions & 106 deletions src/OpenTelemetry/Logs/OpenTelemetryLogger.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand All @@ -38,7 +37,8 @@ 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) || Sdk.SuppressInstrumentation)
if (!this.IsEnabled(logLevel)
|| Sdk.SuppressInstrumentation)
{
return;
}
Expand All @@ -54,7 +54,7 @@ public void Log<TState>(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);
Expand All @@ -73,9 +73,9 @@ public bool IsEnabled(LogLevel logLevel)

private IReadOnlyList<KeyValuePair<string, object>> ParseState<TState>(TState state)
{
if (state is IReadOnlyList<KeyValuePair<string, object>>)
if (state is IReadOnlyList<KeyValuePair<string, object>> stateList)
{
return StateValueListParser<TState>.ParseStateFunc(state);
return stateList;
}
else if (state is IEnumerable<KeyValuePair<string, object>> stateValues)
{
Expand All @@ -89,107 +89,6 @@ private IReadOnlyList<KeyValuePair<string, object>> ParseState<TState>(TState st
};
}
}

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
19 changes: 15 additions & 4 deletions src/OpenTelemetry/Logs/OpenTelemetryLoggerOptions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -25,18 +25,29 @@ 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.
/// 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.
/// Gets or sets a value indicating whether or not formatted log message
/// should be included on generated <see cref="LogRecord"/>s. Default
/// value: False.
/// </summary>
public bool IncludeMessage { get; set; }
public bool IncludeFormattedMessage { 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.
/// 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>
/// <remarks>
/// Note: When <see cref="ParseStateValues"/> is set to <see
/// langword="true"/> <see cref="LogRecord.State"/> will always be <see
/// langword="null"/>.
/// </remarks>
public bool ParseStateValues { get; set; }

/// <summary>
Expand Down
Loading

0 comments on commit b021b63

Please sign in to comment.