Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Logs-branch] More spec-compliant handling of InstrumentationScope #3762

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 7 additions & 1 deletion src/OpenTelemetry.Api/InstrumentationScope.cs
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,8 @@ namespace OpenTelemetry;
/// </summary>
public sealed class InstrumentationScope
{
internal IReadOnlyDictionary<string, object>? AttributeBacking;

/// <summary>
/// Initializes a new instance of the <see cref="InstrumentationScope"/> class.
/// </summary>
Expand Down Expand Up @@ -63,5 +65,9 @@ public InstrumentationScope(string? name)
/// Gets the attributes which should be associated with log records created
/// by the instrumentation library.
/// </summary>
public IReadOnlyDictionary<string, object>? Attributes { get; init; }
public IReadOnlyDictionary<string, object>? Attributes
{
get => this.AttributeBacking;
init => this.AttributeBacking = value;
}
}
3 changes: 3 additions & 0 deletions src/OpenTelemetry.Api/Internal/SemanticConventions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -107,5 +107,8 @@ internal static class SemanticConventions
public const string AttributeExceptionType = "exception.type";
public const string AttributeExceptionMessage = "exception.message";
public const string AttributeExceptionStacktrace = "exception.stacktrace";

public const string AttributeLogEventDomain = "event.domain";
public const string AttributeLogEventName = "event.name";
}
}
42 changes: 41 additions & 1 deletion src/OpenTelemetry.Api/Logs/LoggerOptions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,9 @@

#nullable enable

using System.Collections.Generic;
using OpenTelemetry.Internal;
using OpenTelemetry.Trace;

namespace OpenTelemetry.Logs;

Expand Down Expand Up @@ -62,7 +64,45 @@ public LoggerOptions(InstrumentationScope instrumentationScope)
/// <summary>
/// Gets the domain of events emitted by the instrumentation library.
/// </summary>
public string? EventDomain { get; init; }
public string? EventDomain
{
get
{
var attributes = this.InstrumentationScope.AttributeBacking;
if (attributes != null && attributes.TryGetValue(SemanticConventions.AttributeLogEventDomain, out var eventDomain))
{
return eventDomain as string;
}

return null;
}

init
{
var attributes = this.InstrumentationScope.AttributeBacking;

Dictionary<string, object> newAttributes = new(attributes?.Count + 1 ?? 1);

if (attributes != null)
{
foreach (var kvp in attributes)
{
newAttributes.Add(kvp.Key, kvp.Value);
}
}

if (value != null)
{
newAttributes[SemanticConventions.AttributeLogEventDomain] = value;
}
else
{
newAttributes.Remove(SemanticConventions.AttributeLogEventDomain);
}

this.InstrumentationScope.AttributeBacking = newAttributes;
}
}

/// <summary>
/// Gets a value indicating whether or not trace context should
Expand Down
23 changes: 23 additions & 0 deletions src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -161,6 +161,29 @@ void ProcessScope(LogRecordScope scope, ConsoleLogRecordExporter exporter)
}
}

var instrumentationScope = logRecord.InstrumentationScope;
if (instrumentationScope != null)
{
this.WriteLine($"{"\nInstrumentationScope associated with LogRecord:",-RightPaddingLength}");
this.WriteLine($"{"Name:",-RightPaddingLength}{logRecord.InstrumentationScope.Name}");
if (instrumentationScope.Version != null)
{
this.WriteLine($"{"Version:",-RightPaddingLength}{logRecord.InstrumentationScope.Version}");
}

if (instrumentationScope.Attributes != null)
{
this.WriteLine("Attributes (Key:Value):");
foreach (var attribute in instrumentationScope.Attributes)
{
if (ConsoleTagTransformer.Instance.TryTransformTag(attribute, out var result))
{
this.WriteLine($"{string.Empty,-4}{result}");
}
}
}
}

this.WriteLine(string.Empty);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -33,29 +33,73 @@ internal static class LogRecordExtensions
{
private static readonly string[] SeverityTextMapping = new string[]
{
null, "Trace", "Debug", "Information", "Warning", "Error", "Fatal",
"Trace", "Debug", "Information", "Warning", "Error", "Fatal",
Copy link
Member

@alanwest alanwest Oct 13, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Something to come back to in another PR maybe...

I think these are somewhat inspired by a combination of ILogger and the LogRecord data model... but technically, I think SeverityText is supposed to be the name as it's known by the logging framework being used see: https://github.com/open-telemetry/opentelemetry-proto/blob/724e427879e3d2bae2edc0218fff06e37b9eb46e/opentelemetry/proto/logs/v1/logs.proto#L144-L146

The SeverityNumber (which I don't think we're using today) on the other hand is governed by the data model. But even then, each logging framework should probably optionally be responsible for defining any mapping from its severity levels to one of the normalized OTLP severity numbers. See https://github.com/open-telemetry/opentelemetry-proto/blob/724e427879e3d2bae2edc0218fff06e37b9eb46e/opentelemetry/proto/logs/v1/logs.proto#L140-L142

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Wow interesting! At the moment on this branch, you have to specify a spec value or null:

public LogRecordSeverity? Severity { get; set; } = null;

That makes it the appender's job to map to spec a la:

private static LogRecordSeverity ConvertEventLevelToLogLevel(EventLevel eventLevel)
{
return eventLevel switch
{
EventLevel.Informational => LogRecordSeverity.Information,
EventLevel.Warning => LogRecordSeverity.Warning,
EventLevel.Error => LogRecordSeverity.Error,
EventLevel.Critical => LogRecordSeverity.Fatal,
_ => LogRecordSeverity.Trace,
};
}

We'll have to make changes to support passing the raw original log level as a string in addition to the spec value. Is the raw non-normalized value useful? 🤣

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is the raw non-normalized value useful?

Yea, hard to say, maybe?

If you've been using some logging framework for 30 years, you're probably pretty accustomed to its nomenclature and not so much OpenTelemetry's. So, I guess it might make analyzing logs more familiar to an end user like this?

Also see https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/logs/data-model.md#field-severitytext

};

internal static void AddBatch(
this OtlpCollector.ExportLogsServiceRequest request,
OtlpResource.Resource processResource,
in Batch<LogRecord> logRecordBatch)
{
Dictionary<string, OtlpLogs.ScopeLogs> logsByLibrary = new Dictionary<string, OtlpLogs.ScopeLogs>();
var resourceLogs = new OtlpLogs.ResourceLogs
{
Resource = processResource,
};
request.ResourceLogs.Add(resourceLogs);

var scopeLogs = new OtlpLogs.ScopeLogs();
resourceLogs.ScopeLogs.Add(scopeLogs);
OtlpLogs.ScopeLogs currentScopeLogs = null;

foreach (var logRecord in logRecordBatch)
{
var otlpLogRecord = logRecord.ToOtlpLog();
if (otlpLogRecord != null)
{
scopeLogs.LogRecords.Add(otlpLogRecord);
var instrumentationScope = logRecord.InstrumentationScope;

var instrumentationScopeName = instrumentationScope.Name ?? string.Empty;

if (currentScopeLogs == null || currentScopeLogs.Scope.Name != instrumentationScopeName)
{
if (!logsByLibrary.TryGetValue(instrumentationScopeName, out var scopeLogs))
{
var scope = new OtlpCommon.InstrumentationScope()
{
Name = instrumentationScopeName,
};

if (instrumentationScope?.Version != null)
{
scope.Version = instrumentationScope.Version;
}

var attributes = instrumentationScope?.Attributes;
if (attributes != null)
{
foreach (var attribute in attributes)
{
if (OtlpKeyValueTransformer.Instance.TryTransformTag(
attribute,
out var otlpAttribute))
{
scope.Attributes.Add(otlpAttribute);
}
}
}

scopeLogs = new OtlpLogs.ScopeLogs
{
Scope = scope,
};

logsByLibrary.Add(instrumentationScopeName, scopeLogs);
resourceLogs.ScopeLogs.Add(scopeLogs);
}

currentScopeLogs = scopeLogs;
}

currentScopeLogs.LogRecords.Add(otlpLogRecord);
}
}
}
Expand All @@ -71,9 +115,13 @@ internal static OtlpLogs.LogRecord ToOtlpLog(this LogRecord logRecord)
{
TimeUnixNano = (ulong)logRecord.Timestamp.ToUnixTimeNanoseconds(),
SeverityNumber = GetSeverityNumber(logRecord.Severity),
SeverityText = SeverityTextMapping[logRecord.Severity.HasValue ? ((int)logRecord.Severity.Value) + 1 : 0],
};

if (logRecord.Severity.HasValue)
{
otlpLogRecord.SeverityText = SeverityTextMapping[(int)logRecord.Severity.Value];
}

if (!string.IsNullOrEmpty(logRecord.CategoryName))
{
// TODO:
Expand Down
1 change: 1 addition & 0 deletions src/OpenTelemetry/Logs/LogRecord.cs
Original file line number Diff line number Diff line change
Expand Up @@ -329,6 +329,7 @@ internal LogRecord Copy()

var copy = new LogRecord()
{
InstrumentationScope = this.InstrumentationScope,
Data = this.Data,
ILoggerData = this.ILoggerData.Copy(),
Attributes = this.Attributes == null ? null : new List<KeyValuePair<string, object?>>(this.Attributes),
Expand Down
14 changes: 8 additions & 6 deletions src/OpenTelemetry/Logs/LoggerSdk.cs
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@
using System.Collections.Generic;
using System.Diagnostics;
using OpenTelemetry.Internal;
using OpenTelemetry.Trace;

namespace OpenTelemetry.Logs;

Expand All @@ -44,9 +45,13 @@ public LoggerSdk(
/// <inheritdoc />
public override void EmitEvent(string name, in LogRecordData data, in LogRecordAttributeList attributes = default)
{
// Note: This method will throw if event.name or event.domain is missing
// or null. This was done intentionally see discussion:
// https://github.com/open-telemetry/opentelemetry-specification/pull/2768#discussion_r972447436

Guard.ThrowIfNullOrWhitespace(name);

string eventDomain = this.EnsureEventDomain();
this.EnsureEventDomain();
Copy link
Member

@alanwest alanwest Oct 13, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fine as a TODO to follow up on, but throwing here should probably be vetted with the spec. I think normally we'd not allow for exceptions in this circumstance. Spec says:

Events require the event.domain attribute. The API MUST not allow creating an Event if the Logger instance doesn't have event.domain scope attribute.

This statement should be clarified. This might be a scenario where the SDK should log, but not throw an exception.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This seemed weird to me as well! I asked about it, here's the reply I got:

open-telemetry/opentelemetry-specification#2768 (comment)

I'll drop a comment with that link in there for now.


var provider = this.loggerProvider;
var processor = provider.Processor;
Expand All @@ -65,8 +70,7 @@ public override void EmitEvent(string name, in LogRecordData data, in LogRecordA

Debug.Assert(exportedAttributes != null, "exportedAttributes was null");

exportedAttributes!.Add(new KeyValuePair<string, object?>("event.name", name));
exportedAttributes!.Add(new KeyValuePair<string, object?>("event.domain", eventDomain));
exportedAttributes!.Add(new KeyValuePair<string, object?>(SemanticConventions.AttributeLogEventName, name));

logRecord.Attributes = exportedAttributes;

Expand Down Expand Up @@ -104,7 +108,7 @@ public override void EmitLog(in LogRecordData data, in LogRecordAttributeList at
}
}

private string EnsureEventDomain()
private void EnsureEventDomain()
{
string? eventDomain = this.eventDomain;

Expand All @@ -119,7 +123,5 @@ private string EnsureEventDomain()

this.eventDomain = eventDomain;
}

return eventDomain!;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@
using OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation;
using OpenTelemetry.Internal;
using OpenTelemetry.Logs;
using OpenTelemetry.Proto.Collector.Logs.V1;
using OpenTelemetry.Tests;
using OpenTelemetry.Trace;
using Xunit;
Expand Down Expand Up @@ -485,5 +486,53 @@ public void CheckToOtlpLogRecordExceptionAttributes()
Assert.Contains(SemanticConventions.AttributeExceptionStacktrace, otlpLogRecordAttributes);
Assert.Contains(logRecord.Exception.ToInvariantString(), otlpLogRecordAttributes);
}

[Fact]
public void CheckAddBatchInstrumentationScopeProcessed()
{
List<LogRecord> exportedLogRecords = new();

using (var provider = Sdk.CreateLoggerProviderBuilder()
.AddInMemoryExporter(exportedLogRecords)
.Build())
{
var loggerA = provider.GetLogger(new InstrumentationScope("testLogger1")
{
Attributes = new Dictionary<string, object> { ["mycustom.key1"] = "value1" },
});
var loggerB = provider.GetLogger(
new LoggerOptions(
new InstrumentationScope("testLogger2")
{
Attributes = new Dictionary<string, object> { ["mycustom.key2"] = "value2" },
})
{
EventDomain = "testLogger2EventDomain",
});

loggerA.EmitLog(default, default);
loggerB.EmitEvent("event1", default, default);
}

Assert.Equal(2, exportedLogRecords.Count);

var batch = new Batch<LogRecord>(exportedLogRecords.ToArray(), 2);

ExportLogsServiceRequest request = new();

request.AddBatch(new(), in batch);

Assert.Equal(2, request.ResourceLogs[0].ScopeLogs.Count);

Assert.Equal("testLogger1", request.ResourceLogs[0].ScopeLogs[0].Scope.Name);
Assert.Equal("mycustom.key1", request.ResourceLogs[0].ScopeLogs[0].Scope.Attributes[0].Key);
Assert.Equal("value1", request.ResourceLogs[0].ScopeLogs[0].Scope.Attributes[0].Value.StringValue);

Assert.Equal("testLogger2", request.ResourceLogs[0].ScopeLogs[1].Scope.Name);
Assert.Equal("mycustom.key2", request.ResourceLogs[0].ScopeLogs[1].Scope.Attributes[0].Key);
Assert.Equal("value2", request.ResourceLogs[0].ScopeLogs[1].Scope.Attributes[0].Value.StringValue);
Assert.Equal(SemanticConventions.AttributeLogEventDomain, request.ResourceLogs[0].ScopeLogs[1].Scope.Attributes[1].Key);
Assert.Equal("testLogger2EventDomain", request.ResourceLogs[0].ScopeLogs[1].Scope.Attributes[1].Value.StringValue);
}
}
}