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.

Sign up for GitHub

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

Jump to bottom

Add include_trace_context property to logger builder #5366

Closed
wants to merge 2 commits into from
Closed

Add include_trace_context property to logger builder #5366

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
b8df7af
Add include_trace_context property to logger builder
jack-berg Apr 10, 2023
c03cadf
Merge branch 'main' of https://github.com/open-telemetry/opentelemetr…
jack-berg Apr 11, 2023
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
5 changes: 5 additions & 0 deletions api/logs/src/main/java/io/opentelemetry/api/logs/DefaultLoggerProvider.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,11 @@ public LoggerBuilder setInstrumentationVersion(String instrumentationVersion) {
return this;
}

@Override
public LoggerBuilder excludeTraceContext() {
return this;
}

@Override
public Logger build() {
return DefaultLogger.getInstance();
Expand Down
10 changes: 10 additions & 0 deletions api/logs/src/main/java/io/opentelemetry/api/logs/LoggerBuilder.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,8 @@

package io.opentelemetry.api.logs;

import io.opentelemetry.context.Context;

/**
* Builder class for creating {@link Logger} instances.
*
Expand Down Expand Up @@ -32,6 +34,14 @@ public interface LoggerBuilder {
*/
LoggerBuilder setInstrumentationVersion(String instrumentationScopeVersion);

/**
* Specify that emitted log records SHOULD NOT automatically include trace context from the {@link
* Context#current()}.
Comment on lines +38 to +39
Copy link
Contributor

Choose a reason for hiding this comment

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

I wonder if we should say "span context" rather than "trace context" (since I don't think that's a thing outside of the W3C propagator). Also, should we include a link to the SpanContext class in the javadoc for completeness?

*
* @return this
*/
LoggerBuilder excludeTraceContext();
Copy link
Member

Choose a reason for hiding this comment

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

👍

Copy link
Contributor

Choose a reason for hiding this comment

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

the name of this seems weird to me... since it's only about the span context, not the trace as a whole. 🤔 Is this something that should be adjusted in the spec?

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 one is a bit weird. SpanContext shows up in the trace API specification, and in our API, yet the spec log data model refers to these fields as "Trace Context Fields". I can argue both side of this:

In favor of trace context:

  • Its the context that links logs to the "tracing signal"
  • It contains more than just a span's context (i.e trace id and trace flags)
  • W3C refers to this set of things as

In favor of span context:

  • We have a SpanContext interface
  • The spec refers to this bag of data (spanid, traceid, trace flags, trace state) as SpanContext

Given that the log data model is stable, can we change the log data model to refer to "Span Context Fields" instead of trace context fields? If so, we could / should change this to include_span_context instead of include_trace_context.

@tigrannajaryan curious to get your thoughts on this.

Copy link
Member

Choose a reason for hiding this comment

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

I think we have been using Trace Context and Span Context interchangeably a lot. Span Context is probably a slightly more accurate term since it matters which span in a trace we are referring to from a log. I don't mind renaming this in the spec and in the data model and I don't think it is a breaking change, to me it is just a terminology clarification, we should be able to do it and there are no functional changes.

Copy link
Member

Choose a reason for hiding this comment

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

Actually, one thing that may prevent us from doing it is that we consider it to be valid for a Log Record to reference a trace_id but have no associated span_id. You won't encounter it in Otel-generated data but some weird external data sources like this may be possible so we allowed for it in the data model.

Copy link
Member Author

Choose a reason for hiding this comment

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

I think we have been using Trace Context and Span Context interchangeably a lot.

That's been my experience as well. Here are usage of trace context, tracecontext, span context and spancontext in the specification.

I don't feel strongly either way about this one.

Copy link
Member Author

Choose a reason for hiding this comment

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

If span context and trace context are used interchangeably, its probably not a big deal for otel java to name this excludeSpanContext instead, given that we have a SpanContext interface which would be good to reference in the javadoc.

Copy link
Contributor

Choose a reason for hiding this comment

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

how about just "excludeContext" in case we might want to also start pulling in baggage or something later?


/**
* Gets or creates a {@link Logger} instance.
*
Expand Down
22 changes: 19 additions & 3 deletions sdk/logs/src/main/java/io/opentelemetry/sdk/logs/SdkLogRecordBuilder.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
import io.opentelemetry.api.logs.LogRecordBuilder;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.context.Context;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.internal.AttributesMap;
Expand All @@ -24,6 +25,7 @@ final class SdkLogRecordBuilder implements LogRecordBuilder {
private final LogLimits logLimits;

private final InstrumentationScopeInfo instrumentationScopeInfo;
private final boolean includeTraceContext;
private long timestampEpochNanos;
@Nullable private Context context;
private Severity severity = Severity.UNDEFINED_SEVERITY_NUMBER;
Expand All @@ -32,10 +34,13 @@ final class SdkLogRecordBuilder implements LogRecordBuilder {
@Nullable private AttributesMap attributes;

SdkLogRecordBuilder(
LoggerSharedState loggerSharedState, InstrumentationScopeInfo instrumentationScopeInfo) {
LoggerSharedState loggerSharedState,
InstrumentationScopeInfo instrumentationScopeInfo,
boolean includeTraceContext) {
this.loggerSharedState = loggerSharedState;
this.logLimits = loggerSharedState.getLogLimits();
this.instrumentationScopeInfo = instrumentationScopeInfo;
this.includeTraceContext = includeTraceContext;
}

@Override
Expand Down Expand Up @@ -94,7 +99,18 @@ public void emit() {
if (loggerSharedState.hasBeenShutdown()) {
return;
}
Context context = this.context == null ? Context.current() : this.context;
SpanContext spanContext;
Context context;
if (this.context == null) {
context = Context.current();
spanContext =
includeTraceContext
? Span.fromContext(context).getSpanContext()
: SpanContext.getInvalid();
} else {
context = this.context;
spanContext = Span.fromContext(context).getSpanContext();
}
loggerSharedState
.getLogRecordProcessor()
.onEmit(
Expand All @@ -106,7 +122,7 @@ public void emit() {
this.timestampEpochNanos == 0
? this.loggerSharedState.getClock().now()
: this.timestampEpochNanos,
Span.fromContext(context).getSpanContext(),
spanContext,
severity,
severityText,
body,
Expand Down
16 changes: 14 additions & 2 deletions sdk/logs/src/main/java/io/opentelemetry/sdk/logs/SdkLogger.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,16 +14,28 @@ final class SdkLogger implements Logger {

private final LoggerSharedState loggerSharedState;
private final InstrumentationScopeInfo instrumentationScopeInfo;
private final boolean includeTraceContext;

SdkLogger(
LoggerSharedState loggerSharedState, InstrumentationScopeInfo instrumentationScopeInfo) {
LoggerSharedState loggerSharedState,
InstrumentationScopeInfo instrumentationScopeInfo,
boolean includeTraceContext) {
this.loggerSharedState = loggerSharedState;
this.instrumentationScopeInfo = instrumentationScopeInfo;
this.includeTraceContext = includeTraceContext;
}

SdkLogger withIncludeTraceContext(boolean includeTraceContext) {
if (this.includeTraceContext != includeTraceContext) {
return new SdkLogger(loggerSharedState, instrumentationScopeInfo, includeTraceContext);
}
return this;
}

@Override
public LogRecordBuilder logRecordBuilder() {
return new SdkLogRecordBuilder(loggerSharedState, instrumentationScopeInfo);
return new SdkLogRecordBuilder(
loggerSharedState, instrumentationScopeInfo, includeTraceContext);
}

// VisibleForTesting
Expand Down
12 changes: 10 additions & 2 deletions sdk/logs/src/main/java/io/opentelemetry/sdk/logs/SdkLoggerBuilder.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ final class SdkLoggerBuilder implements LoggerBuilder {
private final String instrumentationScopeName;
@Nullable private String instrumentationScopeVersion;
@Nullable private String schemaUrl;
private boolean includeTraceContext = true;

SdkLoggerBuilder(ComponentRegistry<SdkLogger> registry, String instrumentationScopeName) {
this.registry = registry;
Expand All @@ -34,9 +35,16 @@ public SdkLoggerBuilder setInstrumentationVersion(String instrumentationScopeVer
return this;
}

@Override
public LoggerBuilder excludeTraceContext() {
this.includeTraceContext = false;
return this;
}

@Override
public SdkLogger build() {
return registry.get(
instrumentationScopeName, instrumentationScopeVersion, schemaUrl, Attributes.empty());
return registry
.get(instrumentationScopeName, instrumentationScopeVersion, schemaUrl, Attributes.empty())
.withIncludeTraceContext(includeTraceContext);
}
}
4 changes: 3 additions & 1 deletion sdk/logs/src/main/java/io/opentelemetry/sdk/logs/SdkLoggerProvider.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,9 @@ public static SdkLoggerProviderBuilder builder() {
new LoggerSharedState(resource, logLimitsSupplier, logRecordProcessor, clock);
this.loggerComponentRegistry =
new ComponentRegistry<>(
instrumentationScopeInfo -> new SdkLogger(sharedState, instrumentationScopeInfo));
instrumentationScopeInfo ->
new SdkLogger(
sharedState, instrumentationScopeInfo, /* includeTraceContext= */ true));
this.isNoopLogRecordProcessor = logRecordProcessor instanceof NoopLogRecordProcessor;
}

Expand Down
95 changes: 85 additions & 10 deletions sdk/logs/src/test/java/io/opentelemetry/sdk/logs/SdkLogRecordBuilderTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
import io.opentelemetry.api.trace.TraceFlags;
import io.opentelemetry.api.trace.TraceState;
import io.opentelemetry.context.Context;
import io.opentelemetry.context.Scope;
import io.opentelemetry.sdk.common.Clock;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.Body;
Expand All @@ -38,21 +39,39 @@ class SdkLogRecordBuilderTest {

private static final Resource RESOURCE = Resource.empty();
private static final InstrumentationScopeInfo SCOPE_INFO = InstrumentationScopeInfo.empty();
private static final SpanContext SPAN_CONTEXT1 =
SpanContext.create(
"33333333333333333333333333333333",
"7777777777777777",
TraceFlags.getSampled(),
TraceState.getDefault());
private static final SpanContext SPAN_CONTEXT2 =
SpanContext.create(
"44444444444444444444444444444444",
"8888888888888888",
TraceFlags.getSampled(),
TraceState.getDefault());

@Mock LoggerSharedState loggerSharedState;

private final AtomicReference<Context> emittedContext = new AtomicReference<>();
private final AtomicReference<ReadWriteLogRecord> emittedLog = new AtomicReference<>();
private SdkLogRecordBuilder builder;

@BeforeEach
void setup() {
when(loggerSharedState.getLogLimits()).thenReturn(LogLimits.getDefault());
when(loggerSharedState.getLogRecordProcessor())
.thenReturn((context, logRecord) -> emittedLog.set(logRecord));
.thenReturn(
(context, logRecord) -> {
emittedContext.set(context);
emittedLog.set(logRecord);
});
when(loggerSharedState.getResource()).thenReturn(RESOURCE);
when(loggerSharedState.getClock()).thenReturn(Clock.getDefault());

builder = new SdkLogRecordBuilder(loggerSharedState, SCOPE_INFO);
builder =
new SdkLogRecordBuilder(loggerSharedState, SCOPE_INFO, /* includeTraceContext= */ true);
}

@Test
Expand All @@ -62,20 +81,14 @@ void emit_AllFields() {
String bodyStr = "body";
String sevText = "sevText";
Severity severity = Severity.DEBUG3;
SpanContext spanContext =
SpanContext.create(
"33333333333333333333333333333333",
"7777777777777777",
TraceFlags.getSampled(),
TraceState.getDefault());

builder.setBody(bodyStr);
builder.setTimestamp(123, TimeUnit.SECONDS);
builder.setTimestamp(timestamp);
builder.setAttribute(null, null);
builder.setAttribute(AttributeKey.stringKey("k1"), "v1");
builder.setAllAttributes(Attributes.builder().put("k2", "v2").put("k3", "v3").build());
builder.setContext(Span.wrap(spanContext).storeInContext(Context.root()));
builder.setContext(Span.wrap(SPAN_CONTEXT1).storeInContext(Context.root()));
builder.setSeverity(severity);
builder.setSeverityText(sevText);
builder.emit();
Expand All @@ -85,7 +98,7 @@ void emit_AllFields() {
.hasBody(bodyStr)
.hasTimestamp(TimeUnit.SECONDS.toNanos(timestamp.getEpochSecond()) + timestamp.getNano())
.hasAttributes(Attributes.builder().put("k1", "v1").put("k2", "v2").put("k3", "v3").build())
.hasSpanContext(spanContext)
.hasSpanContext(SPAN_CONTEXT1)
.hasSeverity(severity)
.hasSeverityText(sevText);
}
Expand All @@ -107,4 +120,66 @@ void emit_NoFields() {
.hasSpanContext(SpanContext.getInvalid())
.hasSeverity(Severity.UNDEFINED_SEVERITY_NUMBER);
}

@Test
void emit_ImplicitContext_IncludeTraceContext() {
Context context = Span.wrap(SPAN_CONTEXT1).storeInContext(Context.root());
try (Scope unused = context.makeCurrent()) {
builder.emit();
}

// Implicit context should be emitted to processor and corresponding trace context should be
// included on the log record
assertThat(emittedContext.get()).isEqualTo(context);
assertThat(emittedLog.get().toLogRecordData()).hasSpanContext(SPAN_CONTEXT1);
}

@Test
void emit_ImplicitContext_ExcludeTraceContext() {
builder =
new SdkLogRecordBuilder(loggerSharedState, SCOPE_INFO, /* includeTraceContext= */ false);

Context context = Span.wrap(SPAN_CONTEXT1).storeInContext(Context.root());
try (Scope unused = context.makeCurrent()) {
builder.emit();
}

// Implicit context should be emitted to processor, but trace context should NOT be
// automatically included on the log record
assertThat(emittedContext.get()).isEqualTo(context);
assertThat(emittedLog.get().toLogRecordData()).hasSpanContext(SpanContext.getInvalid());
}

@Test
void emit_ExplicitContext_IncludeTraceContext() {
Context context1 = Span.wrap(SPAN_CONTEXT1).storeInContext(Context.root());
Context context2 = Span.wrap(SPAN_CONTEXT2).storeInContext(Context.root());
try (Scope unused = context1.makeCurrent()) {
builder.setContext(context2);
builder.emit();
}

// Explicit context should overrule implicit context, and be emitted to processor and included
// on the log record
assertThat(emittedContext.get()).isEqualTo(context2);
assertThat(emittedLog.get().toLogRecordData()).hasSpanContext(SPAN_CONTEXT2);
}

@Test
void emit_ExplicitContext_ExcludeTraceContext() {
builder =
new SdkLogRecordBuilder(loggerSharedState, SCOPE_INFO, /* includeTraceContext= */ false);
Context context1 = Span.wrap(SPAN_CONTEXT1).storeInContext(Context.root());
Context context2 = Span.wrap(SPAN_CONTEXT2).storeInContext(Context.root());

try (Scope unused = context1.makeCurrent()) {
builder.setContext(context2);
builder.emit();
}

// Explicit context should overrule implicit context, and be emitted to processor and included
// on the log record
assertThat(emittedContext.get()).isEqualTo(context2);
assertThat(emittedLog.get().toLogRecordData()).hasSpanContext(SPAN_CONTEXT2);
}
}
40 changes: 31 additions & 9 deletions sdk/logs/src/test/java/io/opentelemetry/sdk/logs/SdkLoggerProviderTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@

import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.logs.Logger;
import io.opentelemetry.api.logs.LoggerProvider;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.api.trace.Span;
Expand Down Expand Up @@ -215,6 +216,29 @@ void loggerBuilder_DefaultLoggerName() {
.isEqualTo(SdkLoggerProvider.DEFAULT_LOGGER_NAME);
}

@Test
void loggerBuilder_ExcludeTraceContext() {
Logger loggerWithTraceContext = sdkLoggerProvider.loggerBuilder("test").build();
Logger loggerWithoutTraceContext =
sdkLoggerProvider.loggerBuilder("test").excludeTraceContext().build();

assertThat(loggerWithTraceContext)
.isSameAs(sdkLoggerProvider.loggerBuilder("test").build())
.isNotSameAs(loggerWithoutTraceContext);
assertThat(loggerWithoutTraceContext)
// includeTraceContext is not part of InstrumentationScopeInfo so obtaining a logger with
// .excludeTraceContext() always results in a new instance
.isNotSameAs(sdkLoggerProvider.loggerBuilder("test").excludeTraceContext().build())
.isNotSameAs(loggerWithTraceContext);

assertThat(loggerWithTraceContext.logRecordBuilder())
.extracting("includeTraceContext")
.isEqualTo(true);
assertThat(loggerWithoutTraceContext.logRecordBuilder())
.extracting("includeTraceContext")
.isEqualTo(false);
}

@Test
void loggerBuilder_NoProcessor_UsesNoop() {
assertThat(SdkLoggerProvider.builder().build().loggerBuilder("test"))
Expand Down Expand Up @@ -299,15 +323,13 @@ void loggerBuilder_ProcessorWithContext() {
.hasAttributes(entry(AttributeKey.stringKey("my-context-key"), "context-value1"));

// With explicit context
try (Scope unused = Context.current().with(contextKey, "context-value2").makeCurrent()) {
sdkLoggerProvider
.loggerBuilder("test")
.build()
.logRecordBuilder()
.setContext(Context.current())
.setBody("log message2")
.emit();
}
sdkLoggerProvider
.loggerBuilder("test")
.build()
.logRecordBuilder()
.setContext(Context.current().with(contextKey, "context-value2"))
.setBody("log message2")
.emit();
assertThat(logRecordData.get())
.hasBody("log message2")
.hasAttributes(entry(AttributeKey.stringKey("my-context-key"), "context-value2"));
Expand Down
2 changes: 1 addition & 1 deletion sdk/logs/src/test/java/io/opentelemetry/sdk/logs/SdkLoggerTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,7 +46,7 @@ void logRecordBuilder() {
when(state.getLogRecordProcessor()).thenReturn(logRecordProcessor);
when(state.getClock()).thenReturn(clock);

SdkLogger logger = new SdkLogger(state, info);
SdkLogger logger = new SdkLogger(state, info, true);
LogRecordBuilder logRecordBuilder = logger.logRecordBuilder();
logRecordBuilder.setBody("foo");

Expand Down