[sdk.logging] More consistent handling of StateValues/Attributes (#4334)

This commit is contained in:
Mikel Blanchard 2023-04-20 10:23:58 -07:00 committed by GitHub
parent bfb3e453ee
commit acbf10aa57
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
20 changed files with 666 additions and 320 deletions

View File

@ -23,15 +23,9 @@ internal class MyRedactionProcessor : BaseProcessor<LogRecord>
{
public override void OnEnd(LogRecord logRecord)
{
if (logRecord.State == null)
if (logRecord.Attributes != null)
{
// When State is null, OTel SDK guarantees StateValues is populated
// TODO: Debug.Assert?
logRecord.StateValues = new MyClassWithRedactionEnumerator(logRecord.StateValues);
}
else if (logRecord.State is IReadOnlyList<KeyValuePair<string, object>> listOfKvp)
{
logRecord.State = new MyClassWithRedactionEnumerator(listOfKvp);
logRecord.Attributes = new MyClassWithRedactionEnumerator(logRecord.Attributes);
}
}
}

View File

@ -5,6 +5,11 @@
* Added direct reference to `System.Text.Encodings.Web` with minimum version of
`4.7.2` in response to [CVE-2021-26701](https://github.com/dotnet/runtime/issues/49377).
* Updated `LogRecord` console output: `Body` is now shown (if set),
`StateValues` are now written as `Attributes`, and `State` is no longer
processed.
([#4334](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4334))
## 1.5.0-alpha.2
Released 2023-Mar-31

View File

@ -81,42 +81,22 @@ namespace OpenTelemetry.Exporter
this.WriteLine($"{"LogRecord.FormattedMessage:",-RightPaddingLength}{logRecord.FormattedMessage}");
}
if (logRecord.State != null)
if (logRecord.Body != null)
{
if (logRecord.State is IReadOnlyList<KeyValuePair<string, object>> listKvp)
{
this.WriteLine("LogRecord.State (Key:Value):");
for (int i = 0; i < listKvp.Count; i++)
{
// Special casing {OriginalFormat}
// See https://github.com/open-telemetry/opentelemetry-dotnet/pull/3182
// for explanation.
var valueToTransform = listKvp[i].Key.Equals("{OriginalFormat}")
? new KeyValuePair<string, object>("OriginalFormat (a.k.a Body)", listKvp[i].Value)
: listKvp[i];
if (ConsoleTagTransformer.Instance.TryTransformTag(valueToTransform, out var result))
{
this.WriteLine($"{string.Empty,-4}{result}");
}
}
}
else
{
this.WriteLine($"{"LogRecord.State:",-RightPaddingLength}{logRecord.State}");
}
this.WriteLine($"{"LogRecord.Body:",-RightPaddingLength}{logRecord.Body}");
}
else if (logRecord.StateValues != null)
if (logRecord.Attributes != null)
{
this.WriteLine("LogRecord.StateValues (Key:Value):");
for (int i = 0; i < logRecord.StateValues.Count; i++)
this.WriteLine("LogRecord.Attributes (Key:Value):");
for (int i = 0; i < logRecord.Attributes.Count; i++)
{
// Special casing {OriginalFormat}
// See https://github.com/open-telemetry/opentelemetry-dotnet/pull/3182
// for explanation.
var valueToTransform = logRecord.StateValues[i].Key.Equals("{OriginalFormat}")
? new KeyValuePair<string, object>("OriginalFormat (a.k.a Body)", logRecord.StateValues[i].Value)
: logRecord.StateValues[i];
var valueToTransform = logRecord.Attributes[i].Key.Equals("{OriginalFormat}")
? new KeyValuePair<string, object>("OriginalFormat (a.k.a Body)", logRecord.Attributes[i].Value)
: logRecord.Attributes[i];
if (ConsoleTagTransformer.Instance.TryTransformTag(valueToTransform, out var result))
{

View File

@ -2,6 +2,14 @@
## Unreleased
* The `OpenTelemetryLoggerOptions.AddOtlpExporter` extension no longer
automatically set `OpenTelemetryLoggerOptions.ParseStateValues` to `true`.
([#4334](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4334))
* Updated to use the new `LogRecord.Attributes` field as `StateValues` is now
marked obsolete.
([#4334](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4334))
## 1.5.0-alpha.2
Released 2023-Mar-31

View File

@ -36,11 +36,6 @@ namespace OpenTelemetry.Logs
/// <summary>
/// Adds OTLP Exporter as a configuration to the OpenTelemetry ILoggingBuilder.
/// </summary>
/// <remarks>
/// Note: AddOtlpExporter automatically sets <see
/// cref="OpenTelemetryLoggerOptions.ParseStateValues"/> to <see
/// langword="true"/>.
/// </remarks>
/// <param name="loggerOptions"><see cref="OpenTelemetryLoggerOptions"/> options to use.</param>
/// <param name="configure">Callback action for configuring <see cref="OtlpExporterOptions"/>.</param>
/// <returns>The instance of <see cref="OpenTelemetryLoggerOptions"/> to chain the calls.</returns>
@ -53,8 +48,6 @@ namespace OpenTelemetry.Logs
OpenTelemetryLoggerOptions loggerOptions,
Action<OtlpExporterOptions> configure)
{
loggerOptions.ParseStateValues = true;
var exporterOptions = new OtlpExporterOptions();
// TODO: We are using span/activity batch environment variable keys

View File

@ -113,18 +113,18 @@ namespace OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation
bodyPopulatedFromFormattedMessage = true;
}
if (logRecord.StateValues != null)
if (logRecord.Attributes != null)
{
foreach (var stateValue in logRecord.StateValues)
foreach (var attribute in logRecord.Attributes)
{
// Special casing {OriginalFormat}
// See https://github.com/open-telemetry/opentelemetry-dotnet/pull/3182
// for explanation.
if (stateValue.Key.Equals("{OriginalFormat}") && !bodyPopulatedFromFormattedMessage)
if (attribute.Key.Equals("{OriginalFormat}") && !bodyPopulatedFromFormattedMessage)
{
otlpLogRecord.Body = new OtlpCommon.AnyValue { StringValue = stateValue.Value as string };
otlpLogRecord.Body = new OtlpCommon.AnyValue { StringValue = attribute.Value as string };
}
else if (OtlpKeyValueTransformer.Instance.TryTransformTag(stateValue, out var result, attributeValueLengthLimit))
else if (OtlpKeyValueTransformer.Instance.TryTransformTag(attribute, out var result, attributeValueLengthLimit))
{
otlpLogRecord.AddAttribute(result, attributeCountLimit);
}

View File

@ -1,3 +1,7 @@
OpenTelemetry.Logs.LogRecord.Attributes.get -> System.Collections.Generic.IReadOnlyList<System.Collections.Generic.KeyValuePair<string!, object?>>?
OpenTelemetry.Logs.LogRecord.Attributes.set -> void
OpenTelemetry.Logs.LogRecord.Body.get -> string?
OpenTelemetry.Logs.LogRecord.Body.set -> void
OpenTelemetry.Metrics.AlwaysOffExemplarFilter
OpenTelemetry.Metrics.AlwaysOffExemplarFilter.AlwaysOffExemplarFilter() -> void
OpenTelemetry.Metrics.AlwaysOnExemplarFilter
@ -43,4 +47,4 @@ OpenTelemetry.Metrics.MetricPoint.GetExponentialHistogramData() -> OpenTelemetry
~override OpenTelemetry.Metrics.AlwaysOnExemplarFilter.ShouldSample(long value, System.ReadOnlySpan<System.Collections.Generic.KeyValuePair<string, object>> tags) -> bool
~override OpenTelemetry.Metrics.TraceBasedExemplarFilter.ShouldSample(double value, System.ReadOnlySpan<System.Collections.Generic.KeyValuePair<string, object>> tags) -> bool
~override OpenTelemetry.Metrics.TraceBasedExemplarFilter.ShouldSample(long value, System.ReadOnlySpan<System.Collections.Generic.KeyValuePair<string, object>> tags) -> bool
OpenTelemetry.Resources.ResourceBuilder.AddDetector(System.Func<System.IServiceProvider!, OpenTelemetry.Resources.IResourceDetector!>! resourceDetectorFactory) -> OpenTelemetry.Resources.ResourceBuilder!
OpenTelemetry.Resources.ResourceBuilder.AddDetector(System.Func<System.IServiceProvider!, OpenTelemetry.Resources.IResourceDetector!>! resourceDetectorFactory) -> OpenTelemetry.Resources.ResourceBuilder!

View File

@ -1,3 +1,7 @@
OpenTelemetry.Logs.LogRecord.Attributes.get -> System.Collections.Generic.IReadOnlyList<System.Collections.Generic.KeyValuePair<string!, object?>>?
OpenTelemetry.Logs.LogRecord.Attributes.set -> void
OpenTelemetry.Logs.LogRecord.Body.get -> string?
OpenTelemetry.Logs.LogRecord.Body.set -> void
OpenTelemetry.Metrics.AlwaysOffExemplarFilter
OpenTelemetry.Metrics.AlwaysOffExemplarFilter.AlwaysOffExemplarFilter() -> void
OpenTelemetry.Metrics.AlwaysOnExemplarFilter

View File

@ -1,3 +1,7 @@
OpenTelemetry.Logs.LogRecord.Attributes.get -> System.Collections.Generic.IReadOnlyList<System.Collections.Generic.KeyValuePair<string!, object?>>?
OpenTelemetry.Logs.LogRecord.Attributes.set -> void
OpenTelemetry.Logs.LogRecord.Body.get -> string?
OpenTelemetry.Logs.LogRecord.Body.set -> void
OpenTelemetry.Metrics.AlwaysOffExemplarFilter
OpenTelemetry.Metrics.AlwaysOffExemplarFilter.AlwaysOffExemplarFilter() -> void
OpenTelemetry.Metrics.AlwaysOnExemplarFilter

View File

@ -1,3 +1,7 @@
OpenTelemetry.Logs.LogRecord.Attributes.get -> System.Collections.Generic.IReadOnlyList<System.Collections.Generic.KeyValuePair<string!, object?>>?
OpenTelemetry.Logs.LogRecord.Attributes.set -> void
OpenTelemetry.Logs.LogRecord.Body.get -> string?
OpenTelemetry.Logs.LogRecord.Body.set -> void
OpenTelemetry.Metrics.AlwaysOffExemplarFilter
OpenTelemetry.Metrics.AlwaysOffExemplarFilter.AlwaysOffExemplarFilter() -> void
OpenTelemetry.Metrics.AlwaysOnExemplarFilter

View File

@ -6,13 +6,20 @@
the `telemetry.sdk.*` attributes defined in the
[specification](https://github.com/open-telemetry/opentelemetry-specification/tree/12fcec1ff255b1535db75708e52a3a21f86f0fae/specification/resource/semantic_conventions#semantic-attributes-with-sdk-provided-default-value).
([#4369](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4369))
* Fixed an issue with `HashCode` computations throwing exceptions on .NET
Standard 2.1 targets.
([#4362](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4362))
* Update value of the resource attribute `telemetry.sdk.version` to show the tag
name which resembles the package version of the SDK.
([#4375](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4375))
* Tweaked the behavior of the `OpenTelemetryLoggerOptions.ParseStateValues`
flag, obsoleted `LogRecord.State` and `LogRecord.StateValues` properties, and
added `LogRecord.Body` and `LogRecord.Attributes` properties.
([#4334](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4334))
## 1.5.0-alpha.2
Released 2023-Mar-31

View File

@ -140,6 +140,15 @@ namespace OpenTelemetry.Internal
}
}
[NonEvent]
public void LoggerParseStateException<TState>(Exception exception)
{
if (this.IsEnabled(EventLevel.Warning, EventKeywords.All))
{
this.LoggerParseStateException(typeof(TState).FullName!, exception.ToInvariantString());
}
}
[Event(4, Message = "Unknown error in SpanProcessor event '{0}': '{1}'.", Level = EventLevel.Error)]
public void SpanProcessorException(string evnt, string ex)
{
@ -284,6 +293,12 @@ namespace OpenTelemetry.Internal
this.WriteEvent(47, key, value);
}
[Event(48, Message = "Exception thrown parsing log state of type '{0}'. Exception: '{1}'", Level = EventLevel.Warning)]
public void LoggerParseStateException(string type, string error)
{
this.WriteEvent(48, type, error);
}
#if DEBUG
public class OpenTelemetryEventListener : EventListener
{

View File

@ -29,9 +29,9 @@ namespace OpenTelemetry.Logs
public sealed class LogRecord
{
internal LogRecordData Data;
internal LogRecordILoggerData ILoggerData;
internal List<KeyValuePair<string, object?>>? AttributeStorage;
internal List<object?>? ScopeStorage;
internal List<object?>? BufferedScopes;
internal int PoolReferenceCount = int.MaxValue;
private static readonly Action<object?, List<object?>> AddScopeToBufferedList = (object? scope, List<object?> state) =>
@ -56,20 +56,38 @@ namespace OpenTelemetry.Logs
Exception? exception,
IReadOnlyList<KeyValuePair<string, object?>>? stateValues)
{
this.Data = new(Activity.Current)
var activity = Activity.Current;
this.Data = new(activity)
{
TimestampBacking = timestamp,
CategoryName = categoryName,
LogLevel = logLevel,
EventId = eventId,
Message = formattedMessage,
Exception = exception,
Body = formattedMessage,
};
this.ScopeProvider = scopeProvider;
this.StateValues = stateValues;
this.State = state;
this.ILoggerData = new()
{
TraceState = activity?.TraceStateString,
CategoryName = categoryName,
LogLevel = logLevel,
FormattedMessage = formattedMessage,
EventId = eventId,
Exception = exception,
State = state,
ScopeProvider = scopeProvider,
};
if (stateValues != null && stateValues.Count > 0)
{
var lastAttribute = stateValues[stateValues.Count - 1];
if (lastAttribute.Key == "{OriginalFormat}"
&& lastAttribute.Value is string template)
{
this.Data.Body = template;
}
this.Attributes = stateValues;
}
}
/// <summary>
@ -116,10 +134,14 @@ namespace OpenTelemetry.Logs
/// <summary>
/// Gets or sets the log trace state.
/// </summary>
/// <remarks>
/// Note: Only set if <see
/// cref="OpenTelemetryLoggerOptions.IncludeTraceState"/> is enabled.
/// </remarks>
public string? TraceState
{
get => this.Data.TraceState;
set => this.Data.TraceState = value;
get => this.ILoggerData.TraceState;
set => this.ILoggerData.TraceState = value;
}
/// <summary>
@ -127,8 +149,8 @@ namespace OpenTelemetry.Logs
/// </summary>
public string? CategoryName
{
get => this.Data.CategoryName;
set => this.Data.CategoryName = value;
get => this.ILoggerData.CategoryName;
set => this.ILoggerData.CategoryName = value;
}
/// <summary>
@ -136,8 +158,8 @@ namespace OpenTelemetry.Logs
/// </summary>
public LogLevel LogLevel
{
get => this.Data.LogLevel;
set => this.Data.LogLevel = value;
get => this.ILoggerData.LogLevel;
set => this.ILoggerData.LogLevel = value;
}
/// <summary>
@ -145,44 +167,86 @@ namespace OpenTelemetry.Logs
/// </summary>
public EventId EventId
{
get => this.Data.EventId;
set => this.Data.EventId = value;
get => this.ILoggerData.EventId;
set => this.ILoggerData.EventId = value;
}
/// <summary>
/// Gets or sets the log formatted message.
/// </summary>
/// <remarks>
/// Note: Set if <see
/// cref="OpenTelemetryLoggerOptions.IncludeFormattedMessage"/> is
/// enabled or <c>{OriginalFormat}</c> attribute (message template) is
/// not found.
/// </remarks>
public string? FormattedMessage
{
get => this.Data.Message;
set => this.Data.Message = value;
get => this.ILoggerData.FormattedMessage;
set => this.ILoggerData.FormattedMessage = value;
}
/// <summary>
/// Gets or sets the raw state attached to the log. Set to <see
/// langword="null"/> when <see
/// cref="OpenTelemetryLoggerOptions.ParseStateValues"/> is enabled.
/// Gets or sets the log body.
/// </summary>
public object? State { get; set; }
/// <remarks>
/// Note: Set to the <c>{OriginalFormat}</c> attribute (message
/// template) if found otherwise the formatted log message.
/// </remarks>
public string? Body
{
get => this.Data.Body;
set => this.Data.Body = value;
}
/// <summary>
/// Gets or sets the parsed state values attached to the log. Set when <see
/// Gets or sets the raw state attached to the log.
/// </summary>
/// <remarks>
/// Note: Set to <see langword="null"/> when <see
/// cref="OpenTelemetryLoggerOptions.ParseStateValues"/> is enabled.
/// </remarks>
[Obsolete("State cannot be accessed safely outside of an ILogger.Log call stack. Use Attributes instead to safely access the data attached to a LogRecord. State will be removed in a future version.")]
public object? State
{
get => this.ILoggerData.State;
set => this.ILoggerData.State = value;
}
/// <summary>
/// Gets or sets the state values attached to the log.
/// </summary>
/// <remarks><inheritdoc cref="Attributes" /></remarks>
[Obsolete("Use Attributes instead StateValues will be removed in a future version.")]
public IReadOnlyList<KeyValuePair<string, object?>>? StateValues
{
get => this.Attributes;
set => this.Attributes = value;
}
/// <summary>
/// Gets or sets the attributes attached to the log.
/// </summary>
/// <remarks>
/// Note: Set when <see
/// cref="OpenTelemetryLoggerOptions.IncludeAttributes"/> is enabled and
/// log record state implements <see cref="IReadOnlyList{T}"/> or <see
/// cref="IEnumerable{T}"/> of <see cref="KeyValuePair{TKey, TValue}"/>s
/// (where TKey is <c>string</c> and TValue is <c>object</c>) or <see
/// cref="OpenTelemetryLoggerOptions.ParseStateValues"/> is enabled
/// otherwise <see langword="null"/>.
/// </summary>
public IReadOnlyList<KeyValuePair<string, object?>>? StateValues { get; set; }
/// </remarks>
public IReadOnlyList<KeyValuePair<string, object?>>? Attributes { get; set; }
/// <summary>
/// Gets or sets the log <see cref="System.Exception"/>.
/// </summary>
public Exception? Exception
{
get => this.Data.Exception;
set => this.Data.Exception = value;
get => this.ILoggerData.Exception;
set => this.ILoggerData.Exception = value;
}
internal IExternalScopeProvider? ScopeProvider { get; set; }
/// <summary>
/// Executes callback for each currently active scope objects in order
/// of creation. All callbacks are guaranteed to be called inline from
@ -197,16 +261,17 @@ namespace OpenTelemetry.Logs
var forEachScopeState = new ScopeForEachState<TState>(callback, state);
if (this.BufferedScopes != null)
var bufferedScopes = this.ILoggerData.BufferedScopes;
if (bufferedScopes != null)
{
foreach (object? scope in this.BufferedScopes)
foreach (object? scope in bufferedScopes)
{
ScopeForEachState<TState>.ForEachScope(scope, forEachScopeState);
}
}
else if (this.ScopeProvider != null)
else
{
this.ScopeProvider.ForEachScope(ScopeForEachState<TState>.ForEachScope, forEachScopeState);
this.ILoggerData.ScopeProvider?.ForEachScope(ScopeForEachState<TState>.ForEachScope, forEachScopeState);
}
}
@ -241,59 +306,50 @@ namespace OpenTelemetry.Logs
// can be safely processed outside of the log call chain.
internal void Buffer()
{
// Note: State values are buffered because some states are not safe
// to access outside of the log call chain. See:
// Note: Attributes are buffered because some states are not safe to
// access outside of the log call chain. See:
// https://github.com/open-telemetry/opentelemetry-dotnet/issues/2905
this.BufferLogStateValues();
this.BufferLogAttributes();
this.BufferLogScopes();
// Note: There is no buffering of "State" only "StateValues". We
// don't inspect "object State" at all. It is undefined what
// exporters will do with "State". Some might ignore it, some might
// attempt to access it as a list. That is potentially dangerous.
// TODO: Investigate what to do here. Should we obsolete State and
// just use the StateValues design?
}
internal LogRecord Copy()
{
// Note: We only buffer scopes here because state values are copied
// Note: We only buffer scopes here because attributes are copied
// directly below.
this.BufferLogScopes();
return new()
{
Data = this.Data,
State = this.State,
StateValues = this.StateValues == null ? null : new List<KeyValuePair<string, object?>>(this.StateValues),
BufferedScopes = this.BufferedScopes == null ? null : new List<object?>(this.BufferedScopes),
ILoggerData = this.ILoggerData.Copy(),
Attributes = this.Attributes == null ? null : new List<KeyValuePair<string, object?>>(this.Attributes),
};
}
/// <summary>
/// Buffers the state values attached to the log into a list so that
/// they can be safely processed after the log message lifecycle has
/// ended.
/// Buffers the attributes attached to the log into a list so that they
/// can be safely processed after the log message lifecycle has ended.
/// </summary>
private void BufferLogStateValues()
private void BufferLogAttributes()
{
var stateValues = this.StateValues;
if (stateValues == null || stateValues == this.AttributeStorage)
var attributes = this.Attributes;
if (attributes == null || attributes == this.AttributeStorage)
{
return;
}
var attributeStorage = this.AttributeStorage ??= new List<KeyValuePair<string, object?>>(stateValues.Count);
var attributeStorage = this.AttributeStorage ??= new List<KeyValuePair<string, object?>>(attributes.Count);
// Note: AddRange here will copy all of the KeyValuePairs from
// stateValues to AttributeStorage. This "captures" the state and
// attributes to AttributeStorage. This "captures" the state and
// fixes issues where the values are generated at enumeration time
// like
// https://github.com/open-telemetry/opentelemetry-dotnet/issues/2905.
attributeStorage.AddRange(stateValues);
attributeStorage.AddRange(attributes);
this.StateValues = attributeStorage;
this.Attributes = attributeStorage;
}
/// <summary>
@ -302,18 +358,54 @@ namespace OpenTelemetry.Logs
/// </summary>
private void BufferLogScopes()
{
if (this.ScopeProvider == null)
var scopeProvider = this.ILoggerData.ScopeProvider;
if (scopeProvider == null)
{
return;
}
var scopeStorage = this.ScopeStorage ??= new List<object?>(LogRecordPoolHelper.DefaultMaxNumberOfScopes);
this.ScopeProvider.ForEachScope(AddScopeToBufferedList, scopeStorage);
scopeProvider.ForEachScope(AddScopeToBufferedList, scopeStorage);
this.ScopeProvider = null;
this.ILoggerData.ScopeProvider = null;
this.BufferedScopes = scopeStorage;
this.ILoggerData.BufferedScopes = scopeStorage;
}
internal struct LogRecordILoggerData
{
public string? TraceState;
public string? CategoryName;
public EventId EventId;
public LogLevel LogLevel;
public string? FormattedMessage;
public Exception? Exception;
public object? State;
public IExternalScopeProvider? ScopeProvider;
public List<object?>? BufferedScopes;
public LogRecordILoggerData Copy()
{
var copy = new LogRecordILoggerData
{
TraceState = this.TraceState,
CategoryName = this.CategoryName,
EventId = this.EventId,
LogLevel = this.LogLevel,
FormattedMessage = this.FormattedMessage,
Exception = this.Exception,
State = this.State,
};
var bufferedScopes = this.BufferedScopes;
if (bufferedScopes != null)
{
copy.BufferedScopes = new List<object?>(bufferedScopes);
}
return copy;
}
}
private readonly struct ScopeForEachState<TState>

View File

@ -17,7 +17,6 @@
#nullable enable
using System.Diagnostics;
using Microsoft.Extensions.Logging;
namespace OpenTelemetry.Logs
{
@ -50,14 +49,12 @@ namespace OpenTelemetry.Logs
{
this.TraceId = activity.TraceId;
this.SpanId = activity.SpanId;
this.TraceState = activity.TraceStateString;
this.TraceFlags = activity.ActivityTraceFlags;
}
else
{
this.TraceId = default;
this.SpanId = default;
this.TraceState = null;
this.TraceFlags = ActivityTraceFlags.None;
}
}
@ -91,35 +88,23 @@ namespace OpenTelemetry.Logs
/// </summary>
public ActivityTraceFlags TraceFlags { get; set; }
/* TODO: Add these when log api/sdk spec is stable.
/// <summary>
/// Gets or sets the log trace state.
/// Gets or sets the original string representation of the severity as it is
/// known at the source.
/// </summary>
public string? TraceState { get; set; }
public string? SeverityText { get; set; } = null;
/// <summary>
/// Gets or sets the log category name.
/// Gets or sets the log severity.
/// </summary>
public string? CategoryName { get; set; } = null;
public LogRecordSeverity? Severity { get; set; } = null;
*/
/// <summary>
/// Gets or sets the log <see cref="Microsoft.Extensions.Logging.LogLevel"/>.
/// Gets or sets the log body.
/// </summary>
public LogLevel LogLevel { get; set; } = LogLevel.Trace;
/// <summary>
/// Gets or sets the log <see cref="Microsoft.Extensions.Logging.EventId"/>.
/// </summary>
public EventId EventId { get; set; } = default;
/// <summary>
/// Gets or sets the log message.
/// </summary>
public string? Message { get; set; } = null;
/// <summary>
/// Gets or sets the log <see cref="System.Exception"/>.
/// </summary>
public Exception? Exception { get; set; } = null;
public string? Body { get; set; } = null;
internal static void SetActivityContext(ref LogRecordData data, Activity? activity = null)
{
@ -127,14 +112,12 @@ namespace OpenTelemetry.Logs
{
data.TraceId = activity.TraceId;
data.SpanId = activity.SpanId;
data.TraceState = activity.TraceStateString;
data.TraceFlags = activity.ActivityTraceFlags;
}
else
{
data.TraceId = default;
data.SpanId = default;
data.TraceState = null;
data.TraceFlags = ActivityTraceFlags.None;
}
}

View File

@ -16,7 +16,9 @@
#nullable enable
using System.ComponentModel;
using System.Diagnostics;
using System.Diagnostics.CodeAnalysis;
using System.Runtime.CompilerServices;
using Microsoft.Extensions.Logging;
using OpenTelemetry.Internal;
@ -51,29 +53,52 @@ namespace OpenTelemetry.Logs
var processor = provider.Processor;
if (processor != null)
{
var activity = Activity.Current;
var pool = provider.LogRecordPool;
var record = pool.Rent();
record.ScopeProvider = provider.IncludeScopes ? this.ScopeProvider : null;
record.State = provider.ParseStateValues ? null : state;
record.StateValues = provider.ParseStateValues ? ParseState(record, state) : null;
record.BufferedScopes = null;
ref LogRecord.LogRecordILoggerData iloggerData = ref record.ILoggerData;
iloggerData.TraceState = provider.IncludeTraceState && activity != null
? activity.TraceStateString
: null;
iloggerData.CategoryName = this.categoryName;
iloggerData.EventId = eventId;
iloggerData.LogLevel = logLevel;
iloggerData.Exception = exception;
iloggerData.ScopeProvider = provider.IncludeScopes ? this.ScopeProvider : null;
iloggerData.BufferedScopes = null;
ref LogRecordData data = ref record.Data;
data.TimestampBacking = DateTime.UtcNow;
data.CategoryName = this.categoryName;
data.LogLevel = logLevel;
data.EventId = eventId;
data.Message = provider.IncludeFormattedMessage ? formatter?.Invoke(state, exception) : null;
data.Exception = exception;
LogRecordData.SetActivityContext(ref data, Activity.Current);
LogRecordData.SetActivityContext(ref data, activity);
var attributes = record.Attributes = provider.IncludeAttributes
? ProcessState(record, ref iloggerData, in state, provider.ParseStateValues)
: null;
if (!TryGetOriginalFormatFromAttributes(attributes, out var originalFormat))
{
var formattedMessage = formatter?.Invoke(state, exception) ?? state?.ToString();
data.Body = formattedMessage;
iloggerData.FormattedMessage = formattedMessage;
}
else
{
data.Body = originalFormat;
iloggerData.FormattedMessage = provider.IncludeFormattedMessage
? formatter?.Invoke(state, exception) ?? state?.ToString()
: null;
}
processor.OnEnd(record);
record.ScopeProvider = null;
iloggerData.ScopeProvider = null;
// Attempt to return the LogRecord to the pool. This will no-op
// if a batch exporter has added a reference.
@ -89,15 +114,22 @@ namespace OpenTelemetry.Logs
public IDisposable BeginScope<TState>(TState state) => this.ScopeProvider?.Push(state) ?? NullScope.Instance;
private static IReadOnlyList<KeyValuePair<string, object?>> ParseState<TState>(LogRecord logRecord, TState state)
private static IReadOnlyList<KeyValuePair<string, object?>>? ProcessState<TState>(
LogRecord logRecord,
ref LogRecord.LogRecordILoggerData iLoggerData,
in TState state,
bool parseStateValues)
{
iLoggerData.State = null;
/* TODO: Enable this if/when LogRecordAttributeList becomes public.
if (state is LogRecordAttributeList logRecordAttributes)
if (typeof(TState) == typeof(LogRecordAttributeList))
{
logRecordAttributes.ApplyToLogRecord(logRecord);
// Note: This cast looks strange, but it is meant for the JIT to optimize/remove.
((LogRecordAttributeList)(object)state!).ApplyToLogRecord(logRecord);
return logRecord.AttributeStorage!;
}
else*/
else */
if (state is IReadOnlyList<KeyValuePair<string, object?>> stateList)
{
return stateList;
@ -115,14 +147,67 @@ namespace OpenTelemetry.Logs
return attributeStorage;
}
}
else if (!parseStateValues || state is null)
{
// Note: This is to preserve legacy behavior where State is
// exposed if we didn't parse state.
iLoggerData.State = state;
return null;
}
else
{
var attributeStorage = logRecord.AttributeStorage ??= new List<KeyValuePair<string, object?>>(LogRecordPoolHelper.DefaultMaxNumberOfAttributes);
attributeStorage.Add(new KeyValuePair<string, object?>(string.Empty, state));
return attributeStorage;
try
{
PropertyDescriptorCollection itemProperties = TypeDescriptor.GetProperties(state);
var attributeStorage = logRecord.AttributeStorage ??= new List<KeyValuePair<string, object?>>(itemProperties.Count);
foreach (PropertyDescriptor? itemProperty in itemProperties)
{
if (itemProperty == null)
{
continue;
}
object? value = itemProperty.GetValue(state);
if (value == null)
{
continue;
}
attributeStorage.Add(new KeyValuePair<string, object?>(itemProperty.Name, value));
}
return attributeStorage;
}
catch (Exception parseException)
{
OpenTelemetrySdkEventSource.Log.LoggerParseStateException<TState>(parseException);
return Array.Empty<KeyValuePair<string, object?>>();
}
}
}
private static bool TryGetOriginalFormatFromAttributes(
IReadOnlyList<KeyValuePair<string, object?>>? attributes,
[NotNullWhen(true)] out string? originalFormat)
{
if (attributes != null && attributes.Count > 0)
{
var lastAttribute = attributes[attributes.Count - 1];
if (lastAttribute.Key == "{OriginalFormat}"
&& lastAttribute.Value is string tempOriginalFormat)
{
originalFormat = tempOriginalFormat;
return true;
}
}
originalFormat = null;
return false;
}
private sealed class NullScope : IDisposable
{
public static NullScope Instance { get; } = new();

View File

@ -32,8 +32,10 @@ namespace OpenTelemetry.Logs
[ProviderAlias("OpenTelemetry")]
public class OpenTelemetryLoggerProvider : BaseProvider, ILoggerProvider, ISupportExternalScope
{
internal readonly bool IncludeScopes;
internal readonly bool IncludeAttributes;
internal readonly bool IncludeFormattedMessage;
internal readonly bool IncludeScopes;
internal readonly bool IncludeTraceState;
internal readonly bool ParseStateValues;
internal BaseProcessor<LogRecord>? Processor;
internal Resource Resource;
@ -82,8 +84,10 @@ namespace OpenTelemetry.Logs
this.ServiceProvider = serviceProvider;
this.IncludeScopes = options.IncludeScopes;
this.IncludeAttributes = options.IncludeAttributes;
this.IncludeFormattedMessage = options.IncludeFormattedMessage;
this.IncludeScopes = options.IncludeScopes;
this.IncludeTraceState = options.IncludeTraceState;
this.ParseStateValues = options.ParseStateValues;
var resourceBuilder = options.ResourceBuilder;

View File

@ -16,6 +16,7 @@
#nullable enable
using System.Diagnostics;
using OpenTelemetry.Internal;
using OpenTelemetry.Resources;
@ -29,32 +30,60 @@ namespace OpenTelemetry.Logs
internal readonly List<BaseProcessor<LogRecord>> Processors = new();
internal ResourceBuilder ResourceBuilder = ResourceBuilder.CreateDefault();
/// <summary>
/// Gets or sets a value indicating whether or not formatted log message
/// should be included on generated <see cref="LogRecord"/>s. Default
/// value: <see langword="false"/>.
/// </summary>
/// <remarks>
/// Note: When set to <see langword="false"/> a formatted log message
/// will not be included if a message template can be found. If a
/// message template is not found, a formatted log message is always
/// included.
/// </remarks>
public bool IncludeFormattedMessage { get; set; }
/// <summary>
/// Gets or sets a value indicating whether or not log scopes should be
/// included on generated <see cref="LogRecord"/>s. Default value:
/// False.
/// <see langword="false"/>.
/// </summary>
public bool IncludeScopes { get; set; }
/// <summary>
/// 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 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.
/// parsed into <see cref="LogRecord.Attributes"/> on generated <see
/// cref="LogRecord"/>s. Default value: <see langword="false"/>.
/// </summary>
/// <remarks>
/// Note: When <see cref="ParseStateValues"/> is set to <see
/// Notes:
/// <list type="bullet">
/// <item>Parsing is only executed when the state logged does NOT
/// implement <see cref="IReadOnlyList{T}"/> or <see
/// cref="IEnumerable{T}"/> where <c>T</c> is <c>KeyValuePair&lt;string,
/// object&gt;</c>.</item>
/// <item>When <see cref="ParseStateValues"/> is set to <see
/// langword="true"/> <see cref="LogRecord.State"/> will always be <see
/// langword="null"/>.
/// langword="null"/>.</item>
/// </list>
/// </remarks>
public bool ParseStateValues { get; set; }
/// <summary>
/// Gets or sets a value indicating whether or not attributes specified
/// via log state should be included on generated <see
/// cref="LogRecord"/>s. Default value: <see langword="true"/>.
/// </summary>
internal bool IncludeAttributes { get; set; } = true;
/// <summary>
/// Gets or sets a value indicating whether or not the <see
/// cref="Activity.TraceStateString"/> for the current <see
/// cref="Activity"/> should be included on generated <see
/// cref="LogRecord"/>s. Default value: <see langword="false"/>.
/// </summary>
internal bool IncludeTraceState { get; set; }
/// <summary>
/// Adds processor to the options.
/// </summary>

View File

@ -37,84 +37,116 @@ namespace OpenTelemetry.Exporter.OpenTelemetryProtocol.Tests
private static readonly SdkLimitOptions DefaultSdkLimitOptions = new();
[Fact]
public void AddOtlpLogExporterOptionsTest()
public void AddOtlpLogExporterReceivesAttributesWithParseStateValueSetToFalse()
{
AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true);
var loggerOptions = new OpenTelemetryLoggerOptions();
Assert.False(loggerOptions.ParseStateValues);
loggerOptions.AddOtlpExporter();
Assert.True(loggerOptions.ParseStateValues);
}
bool optionsValidated = false;
[Fact]
public void AddOtlpLogExporterSetsParseStateValueToTrue()
{
AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true);
var logRecords = new List<LogRecord>();
using var loggerFactory = LoggerFactory.Create(builder =>
{
builder.AddOpenTelemetry(options =>
builder
.AddOpenTelemetry(options => options
.AddInMemoryExporter(logRecords)
.AddOtlpExporter());
builder.Services.Configure<OpenTelemetryLoggerOptions>(o =>
{
options.AddInMemoryExporter(logRecords);
options.AddOtlpExporter();
optionsValidated = true;
Assert.False(o.ParseStateValues);
});
});
Assert.True(optionsValidated);
var logger = loggerFactory.CreateLogger("OtlpLogExporterTests");
logger.LogInformation("Hello from {name} {price}.", "tomato", 2.99);
Assert.Single(logRecords);
var logRecord = logRecords[0];
#pragma warning disable CS0618 // Type or member is obsolete
Assert.Null(logRecord.State);
Assert.NotNull(logRecord.StateValues);
#pragma warning restore CS0618 // Type or member is obsolete
Assert.NotNull(logRecord.Attributes);
}
[Fact]
public void AddOtlpLogExporterParseStateValueCanBeTurnedOff()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void AddOtlpLogExporterParseStateValueCanBeTurnedOff(bool parseState)
{
AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true);
var logRecords = new List<LogRecord>();
using var loggerFactory = LoggerFactory.Create(builder =>
{
builder.AddOpenTelemetry(options =>
{
options.AddInMemoryExporter(logRecords);
options.AddOtlpExporter();
options.ParseStateValues = false;
});
builder
.AddOpenTelemetry(options =>
{
options.ParseStateValues = parseState;
options
.AddInMemoryExporter(logRecords)
.AddOtlpExporter();
});
});
var logger = loggerFactory.CreateLogger("OtlpLogExporterTests");
logger.LogInformation("Hello from {name} {price}.", "tomato", 2.99);
logger.Log(LogLevel.Information, default, new { propertyA = "valueA" }, null, (s, e) => "Custom state log message");
Assert.Single(logRecords);
var logRecord = logRecords[0];
Assert.NotNull(logRecord.State);
Assert.Null(logRecord.StateValues);
#pragma warning disable CS0618 // Type or member is obsolete
if (parseState)
{
Assert.Null(logRecord.State);
Assert.NotNull(logRecord.Attributes);
Assert.Contains(logRecord.Attributes, kvp => kvp.Key == "propertyA" && (string)kvp.Value == "valueA");
}
else
{
Assert.NotNull(logRecord.State);
Assert.Null(logRecord.Attributes);
}
#pragma warning restore CS0618 // Type or member is obsolete
}
[Fact]
public void AddOtlpLogExporterParseStateValueCanBeTurnedOffHosting()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void AddOtlpLogExporterParseStateValueCanBeTurnedOffHosting(bool parseState)
{
var logRecords = new List<LogRecord>();
AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true);
var hostBuilder = new HostBuilder();
hostBuilder.ConfigureLogging(logging => logging.AddOpenTelemetry(options =>
{
options.AddInMemoryExporter(logRecords);
options.AddOtlpExporter();
}));
hostBuilder.ConfigureLogging(logging => logging
.AddOpenTelemetry(options => options
.AddInMemoryExporter(logRecords)
.AddOtlpExporter()));
hostBuilder.ConfigureServices(services =>
services.Configure<OpenTelemetryLoggerOptions>(options => options.ParseStateValues = false));
services.Configure<OpenTelemetryLoggerOptions>(options => options.ParseStateValues = parseState));
var host = hostBuilder.Build();
var loggerFactory = host.Services.GetService<ILoggerFactory>();
var logger = loggerFactory.CreateLogger("OtlpLogExporterTests");
logger.LogInformation("Hello from {name} {price}.", "tomato", 2.99);
logger.Log(LogLevel.Information, default, new { propertyA = "valueA" }, null, (s, e) => "Custom state log message");
Assert.Single(logRecords);
var logRecord = logRecords[0];
Assert.NotNull(logRecord.State);
Assert.Null(logRecord.StateValues);
#pragma warning disable CS0618 // Type or member is obsolete
if (parseState)
{
Assert.Null(logRecord.State);
Assert.NotNull(logRecord.Attributes);
Assert.Contains(logRecord.Attributes, kvp => kvp.Key == "propertyA" && (string)kvp.Value == "valueA");
}
else
{
Assert.NotNull(logRecord.State);
Assert.Null(logRecord.Attributes);
}
#pragma warning restore CS0618 // Type or member is obsolete
}
[Fact]
@ -397,14 +429,10 @@ namespace OpenTelemetry.Exporter.OpenTelemetryProtocol.Tests
otlpLogRecord = logRecord.ToOtlpLog(DefaultSdkLimitOptions);
Assert.NotNull(otlpLogRecord);
if (includeFormattedMessage)
{
Assert.Equal(logRecord.FormattedMessage, otlpLogRecord.Body.StringValue);
}
else
{
Assert.Null(otlpLogRecord.Body);
}
// Formatter is always called if no template can be found.
Assert.Equal(logRecord.FormattedMessage, otlpLogRecord.Body.StringValue);
Assert.Equal(logRecord.Body, otlpLogRecord.Body.StringValue);
logRecords.Clear();
@ -418,16 +446,8 @@ namespace OpenTelemetry.Exporter.OpenTelemetryProtocol.Tests
Assert.NotNull(otlpLogRecord);
// There is no formatter, so no way to populate Body.
// Exporter won't even attempt to do ToString() on State.
if (includeFormattedMessage)
{
Assert.Null(otlpLogRecord.Body);
}
else
{
Assert.Null(otlpLogRecord.Body);
}
// There is no formatter, we call ToString on state
Assert.Equal("state", otlpLogRecord.Body.StringValue);
}
[Fact]

View File

@ -15,8 +15,6 @@
// </copyright>
#if !NETFRAMEWORK
using System;
using System.Collections.Generic;
using Microsoft.Extensions.Logging;
using OpenTelemetry.Exporter;
using Xunit;
@ -42,7 +40,7 @@ namespace OpenTelemetry.Logs.Tests
var state = new LogRecordTest.DisposingState("Hello world");
logRecord.ScopeProvider = scopeProvider;
logRecord.ILoggerData.ScopeProvider = scopeProvider;
logRecord.StateValues = state;
processor.OnEnd(logRecord);
@ -51,10 +49,10 @@ namespace OpenTelemetry.Logs.Tests
Assert.Empty(exportedItems);
Assert.Null(logRecord.ScopeProvider);
Assert.Null(logRecord.ILoggerData.ScopeProvider);
Assert.False(ReferenceEquals(state, logRecord.StateValues));
Assert.NotNull(logRecord.AttributeStorage);
Assert.NotNull(logRecord.BufferedScopes);
Assert.NotNull(logRecord.ILoggerData.BufferedScopes);
KeyValuePair<string, object> actualState = logRecord.StateValues[0];

View File

@ -71,125 +71,197 @@ namespace OpenTelemetry.Logs.Tests
Assert.Equal(logLevel, logLevelRecorded);
}
[Fact]
public void CheckStateForUnstructuredLog()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void CheckStateForUnstructuredLog(bool includeFormattedMessage)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: null);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: o => o.IncludeFormattedMessage = includeFormattedMessage);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
const string message = "Hello, World!";
logger.LogInformation(message);
var state = exportedItems[0].State as IReadOnlyList<KeyValuePair<string, object>>;
Assert.Null(exportedItems[0].State);
var attributes = exportedItems[0].Attributes;
Assert.NotNull(attributes);
// state only has {OriginalFormat}
Assert.Equal(1, state.Count);
Assert.Equal(1, attributes.Count);
Assert.Equal(message, state.ToString());
Assert.Equal(message, exportedItems[0].Body);
if (includeFormattedMessage)
{
Assert.Equal(message, exportedItems[0].FormattedMessage);
}
else
{
Assert.Null(exportedItems[0].FormattedMessage);
}
}
[Fact]
[Theory]
[InlineData(true)]
[InlineData(false)]
[SuppressMessage("CA2254", "CA2254", Justification = "While you shouldn't use interpolation in a log message, this test verifies things work with it anyway.")]
public void CheckStateForUnstructuredLogWithStringInterpolation()
public void CheckStateForUnstructuredLogWithStringInterpolation(bool includeFormattedMessage)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: null);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: o => o.IncludeFormattedMessage = includeFormattedMessage);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
var message = $"Hello from potato {0.99}.";
logger.LogInformation(message);
var state = exportedItems[0].State as IReadOnlyList<KeyValuePair<string, object>>;
Assert.Null(exportedItems[0].State);
var attributes = exportedItems[0].Attributes;
Assert.NotNull(attributes);
// state only has {OriginalFormat}
Assert.Equal(1, state.Count);
Assert.Equal(1, attributes.Count);
Assert.Equal(message, state.ToString());
Assert.Equal(message, exportedItems[0].Body);
if (includeFormattedMessage)
{
Assert.Equal(message, exportedItems[0].FormattedMessage);
}
else
{
Assert.Null(exportedItems[0].FormattedMessage);
}
}
[Fact]
public void CheckStateForStructuredLogWithTemplate()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void CheckStateForStructuredLogWithTemplate(bool includeFormattedMessage)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: null);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: o => o.IncludeFormattedMessage = includeFormattedMessage);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
const string message = "Hello from {name} {price}.";
logger.LogInformation(message, "tomato", 2.99);
var state = exportedItems[0].State as IReadOnlyList<KeyValuePair<string, object>>;
Assert.Null(exportedItems[0].State);
var attributes = exportedItems[0].Attributes;
Assert.NotNull(attributes);
// state has name, price and {OriginalFormat}
Assert.Equal(3, state.Count);
Assert.Equal(3, attributes.Count);
// Check if state has name
Assert.Contains(state, item => item.Key == "name");
Assert.Equal("tomato", state.First(item => item.Key == "name").Value);
Assert.Contains(attributes, item => item.Key == "name");
Assert.Equal("tomato", attributes.First(item => item.Key == "name").Value);
// Check if state has price
Assert.Contains(state, item => item.Key == "price");
Assert.Equal(2.99, state.First(item => item.Key == "price").Value);
Assert.Contains(attributes, item => item.Key == "price");
Assert.Equal(2.99, attributes.First(item => item.Key == "price").Value);
// Check if state has OriginalFormat
Assert.Contains(state, item => item.Key == "{OriginalFormat}");
Assert.Equal(message, state.First(item => item.Key == "{OriginalFormat}").Value);
Assert.Contains(attributes, item => item.Key == "{OriginalFormat}");
Assert.Equal(message, attributes.First(item => item.Key == "{OriginalFormat}").Value);
Assert.Equal($"Hello from tomato 2.99.", state.ToString());
Assert.Equal(message, exportedItems[0].Body);
if (includeFormattedMessage)
{
Assert.Equal("Hello from tomato 2.99.", exportedItems[0].FormattedMessage);
}
else
{
Assert.Null(exportedItems[0].FormattedMessage);
}
}
[Fact]
public void CheckStateForStructuredLogWithStrongType()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void CheckStateForStructuredLogWithStrongType(bool includeFormattedMessage)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: null);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: o => o.IncludeFormattedMessage = includeFormattedMessage);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
var food = new Food { Name = "artichoke", Price = 3.99 };
logger.LogInformation("{food}", food);
var state = exportedItems[0].State as IReadOnlyList<KeyValuePair<string, object>>;
Assert.Null(exportedItems[0].State);
var attributes = exportedItems[0].Attributes;
Assert.NotNull(attributes);
// state has food and {OriginalFormat}
Assert.Equal(2, state.Count);
Assert.Equal(2, attributes.Count);
// Check if state has food
Assert.Contains(state, item => item.Key == "food");
Assert.Contains(attributes, item => item.Key == "food");
var foodParameter = (Food)state.First(item => item.Key == "food").Value;
var foodParameter = (Food)attributes.First(item => item.Key == "food").Value;
Assert.Equal(food.Name, foodParameter.Name);
Assert.Equal(food.Price, foodParameter.Price);
// Check if state has OriginalFormat
Assert.Contains(state, item => item.Key == "{OriginalFormat}");
Assert.Equal("{food}", state.First(item => item.Key == "{OriginalFormat}").Value);
Assert.Contains(attributes, item => item.Key == "{OriginalFormat}");
Assert.Equal("{food}", attributes.First(item => item.Key == "{OriginalFormat}").Value);
Assert.Equal(food.ToString(), state.ToString());
Assert.Equal("{food}", exportedItems[0].Body);
if (includeFormattedMessage)
{
Assert.Equal(food.ToString(), exportedItems[0].FormattedMessage);
}
else
{
Assert.Null(exportedItems[0].FormattedMessage);
}
}
[Fact]
public void CheckStateForStructuredLogWithAnonymousType()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void CheckStateForStructuredLogWithAnonymousType(bool includeFormattedMessage)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: null);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: o => o.IncludeFormattedMessage = includeFormattedMessage);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
var anonymousType = new { Name = "pumpkin", Price = 5.99 };
logger.LogInformation("{food}", anonymousType);
var state = exportedItems[0].State as IReadOnlyList<KeyValuePair<string, object>>;
Assert.Null(exportedItems[0].State);
var attributes = exportedItems[0].Attributes;
Assert.NotNull(attributes);
// state has food and {OriginalFormat}
Assert.Equal(2, state.Count);
Assert.Equal(2, attributes.Count);
// Check if state has food
Assert.Contains(state, item => item.Key == "food");
Assert.Contains(attributes, item => item.Key == "food");
var foodParameter = state.First(item => item.Key == "food").Value as dynamic;
var foodParameter = attributes.First(item => item.Key == "food").Value as dynamic;
Assert.Equal(anonymousType.Name, foodParameter.Name);
Assert.Equal(anonymousType.Price, foodParameter.Price);
// Check if state has OriginalFormat
Assert.Contains(state, item => item.Key == "{OriginalFormat}");
Assert.Equal("{food}", state.First(item => item.Key == "{OriginalFormat}").Value);
Assert.Contains(attributes, item => item.Key == "{OriginalFormat}");
Assert.Equal("{food}", attributes.First(item => item.Key == "{OriginalFormat}").Value);
Assert.Equal(anonymousType.ToString(), state.ToString());
Assert.Equal("{food}", exportedItems[0].Body);
if (includeFormattedMessage)
{
Assert.Equal(anonymousType.ToString(), exportedItems[0].FormattedMessage);
}
else
{
Assert.Null(exportedItems[0].FormattedMessage);
}
}
[Fact]
public void CheckStateForStructuredLogWithGeneralType()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void CheckStateForStructuredLogWithGeneralType(bool includeFormattedMessage)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: null);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: o => o.IncludeFormattedMessage = includeFormattedMessage);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
var food = new Dictionary<string, object>
@ -198,30 +270,42 @@ namespace OpenTelemetry.Logs.Tests
["Price"] = 299.99,
};
logger.LogInformation("{food}", food);
var state = exportedItems[0].State as IReadOnlyList<KeyValuePair<string, object>>;
Assert.Null(exportedItems[0].State);
var attributes = exportedItems[0].Attributes;
Assert.NotNull(attributes);
// state only has food and {OriginalFormat}
Assert.Equal(2, state.Count);
Assert.Equal(2, attributes.Count);
// Check if state has food
Assert.Contains(state, item => item.Key == "food");
Assert.Contains(attributes, item => item.Key == "food");
var foodParameter = state.First(item => item.Key == "food").Value as Dictionary<string, object>;
var foodParameter = attributes.First(item => item.Key == "food").Value as Dictionary<string, object>;
Assert.True(food.Count == foodParameter.Count && !food.Except(foodParameter).Any());
// Check if state has OriginalFormat
Assert.Contains(state, item => item.Key == "{OriginalFormat}");
Assert.Equal("{food}", state.First(item => item.Key == "{OriginalFormat}").Value);
Assert.Contains(attributes, item => item.Key == "{OriginalFormat}");
Assert.Equal("{food}", attributes.First(item => item.Key == "{OriginalFormat}").Value);
var prevCulture = CultureInfo.CurrentCulture;
CultureInfo.CurrentCulture = CultureInfo.InvariantCulture;
try
Assert.Equal("{food}", exportedItems[0].Body);
if (includeFormattedMessage)
{
Assert.Equal("[Name, truffle], [Price, 299.99]", state.ToString());
var prevCulture = CultureInfo.CurrentCulture;
CultureInfo.CurrentCulture = CultureInfo.InvariantCulture;
try
{
Assert.Equal("[Name, truffle], [Price, 299.99]", exportedItems[0].FormattedMessage);
}
finally
{
CultureInfo.CurrentCulture = prevCulture;
}
}
finally
else
{
CultureInfo.CurrentCulture = prevCulture;
Assert.Null(exportedItems[0].FormattedMessage);
}
}
@ -237,17 +321,20 @@ namespace OpenTelemetry.Logs.Tests
const string message = "Exception Occurred";
logger.LogInformation(exception, message);
var state = exportedItems[0].State;
var itemCount = state.GetType().GetProperty("Count").GetValue(state);
Assert.Null(exportedItems[0].State);
var attributes = exportedItems[0].Attributes;
Assert.NotNull(attributes);
// state only has {OriginalFormat}
Assert.Equal(1, itemCount);
Assert.Equal(1, attributes.Count);
var loggedException = exportedItems[0].Exception;
Assert.NotNull(loggedException);
Assert.Equal(exceptionMessage, loggedException.Message);
Assert.Equal(message, state.ToString());
Assert.Equal(message, exportedItems[0].Body);
Assert.Null(exportedItems[0].FormattedMessage);
}
[Fact]
@ -380,10 +467,12 @@ namespace OpenTelemetry.Logs.Tests
Assert.Equal(default, logRecord.TraceFlags);
}
[Fact]
public void CheckTraceIdForLogWithinActivityMarkedAsRecordOnly()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void CheckTraceIdForLogWithinActivityMarkedAsRecordOnly(bool includeTraceState)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: null);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: o => o.IncludeTraceState = includeTraceState);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
var sampler = new RecordOnlySampler();
@ -397,6 +486,7 @@ namespace OpenTelemetry.Logs.Tests
.Build();
using var activity = activitySource.StartActivity("Activity");
activity.TraceStateString = "key1=value1";
logger.LogInformation("Log within activity marked as RecordOnly");
var logRecord = exportedItems[0];
@ -406,6 +496,15 @@ namespace OpenTelemetry.Logs.Tests
Assert.Equal(currentActivity.TraceId, logRecord.TraceId);
Assert.Equal(currentActivity.SpanId, logRecord.SpanId);
Assert.Equal(currentActivity.ActivityTraceFlags, logRecord.TraceFlags);
if (includeTraceState)
{
Assert.Equal(currentActivity.TraceStateString, logRecord.TraceState);
}
else
{
Assert.Null(logRecord.TraceState);
}
}
[Fact]
@ -470,17 +569,19 @@ namespace OpenTelemetry.Logs.Tests
logger.Log(LogLevel.Information, default, "Hello World!", null, null);
var logRecord = exportedItems[0];
Assert.Null(logRecord.FormattedMessage);
Assert.Equal("Hello World!", logRecord.FormattedMessage);
Assert.Equal("Hello World!", logRecord.Body);
// Pass null as formatter function
logger.Log(LogLevel.Information, default, "Hello World!", null, null);
logger.Log(LogLevel.Information, default, new CustomState(), null, null);
logRecord = exportedItems[1];
Assert.Null(logRecord.FormattedMessage);
Assert.Equal(CustomState.ToStringValue, logRecord.FormattedMessage);
Assert.Equal(CustomState.ToStringValue, logRecord.Body);
var expectedFormattedMessage = "formatted message";
logger.Log(LogLevel.Information, default, "Hello World!", null, (state, ex) => expectedFormattedMessage);
logRecord = exportedItems[2];
Assert.Equal(expectedFormattedMessage, logRecord.FormattedMessage);
Assert.Equal(expectedFormattedMessage, logRecord.Body);
}
[Fact]
@ -596,25 +697,12 @@ namespace OpenTelemetry.Logs.Tests
Assert.Same(expectedScope3, scopes[2]);
}
[Fact]
public void VerifyParseStateValues_False_UsingStandardExtensions()
[Theory]
[InlineData(true)]
[InlineData(false)]
public void VerifyParseStateValues_UsingStandardExtensions(bool parseStateValues)
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: options => options.ParseStateValues = false);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
// Tests state parsing with standard extensions.
logger.LogInformation("{Product} {Year}!", "OpenTelemetry", 2021);
var logRecord = exportedItems[0];
Assert.NotNull(logRecord.State);
Assert.Null(logRecord.StateValues);
}
[Fact]
public void VerifyParseStateValues_True_UsingStandardExtensions()
{
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: options => options.ParseStateValues = true);
using var loggerFactory = InitializeLoggerFactory(out List<LogRecord> exportedItems, configure: options => options.ParseStateValues = parseStateValues);
var logger = loggerFactory.CreateLogger<LogRecordTest>();
// Tests state parsing with standard extensions.
@ -622,7 +710,9 @@ namespace OpenTelemetry.Logs.Tests
logger.LogInformation("{Product} {Year}!", "OpenTelemetry", 2021);
var logRecord = exportedItems[0];
Assert.NotNull(logRecord.StateValues);
Assert.Null(logRecord.State);
Assert.NotNull(logRecord.StateValues);
Assert.Equal(3, logRecord.StateValues.Count);
Assert.Equal(new KeyValuePair<string, object>("Product", "OpenTelemetry"), logRecord.StateValues[0]);
@ -634,7 +724,9 @@ namespace OpenTelemetry.Logs.Tests
logger.LogInformation("{Product} {Year} {Complex}!", "OpenTelemetry", 2021, complex);
logRecord = exportedItems[1];
Assert.NotNull(logRecord.StateValues);
Assert.Null(logRecord.State);
Assert.NotNull(logRecord.StateValues);
Assert.Equal(4, logRecord.StateValues.Count);
Assert.Equal(new KeyValuePair<string, object>("Product", "OpenTelemetry"), logRecord.StateValues[0]);
@ -739,8 +831,8 @@ namespace OpenTelemetry.Logs.Tests
KeyValuePair<string, object> actualState = logRecord.StateValues[0];
Assert.Equal(string.Empty, actualState.Key);
Assert.Same(state, actualState.Value);
Assert.Equal("Property", actualState.Key);
Assert.Equal("Value", actualState.Value);
}
[Fact]
@ -804,6 +896,26 @@ namespace OpenTelemetry.Logs.Tests
Assert.Equal("scope2", processor.Scopes[1]);
}
[Fact]
public void IncludeStateTest()
{
using var loggerFactory = InitializeLoggerFactory(
out List<LogRecord> exportedItems, configure: options =>
{
options.IncludeAttributes = false;
});
var logger = loggerFactory.CreateLogger<LogRecordTest>();
logger.LogInformation("Hello {world}", "earth");
var logRecord = exportedItems[0];
Assert.Null(logRecord.State);
Assert.Null(logRecord.Attributes);
Assert.Equal("Hello earth", logRecord.Body);
}
private static ILoggerFactory InitializeLoggerFactory(out List<LogRecord> exportedItems, Action<OpenTelemetryLoggerOptions> configure = null)
{
var items = exportedItems = new List<LogRecord>();
@ -946,7 +1058,12 @@ namespace OpenTelemetry.Logs.Tests
private class CustomState
{
public const string ToStringValue = "CustomState.ToString";
public string Property { get; set; }
public override string ToString()
=> ToStringValue;
}
private class ScopeProcessor : BaseProcessor<LogRecord>