Skip to content

Commit

Permalink
Remove log record timestamp default (#5374)
Browse files Browse the repository at this point in the history
  • Loading branch information
jack-berg committed Apr 14, 2023
1 parent 8f6f9e7 commit cbbba71
Show file tree
Hide file tree
Showing 8 changed files with 41 additions and 47 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -71,11 +71,11 @@
import io.opentelemetry.semconv.resource.attributes.ResourceAttributes;
import java.io.UncheckedIOException;
import java.time.Duration;
import java.time.Instant;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
import java.util.concurrent.CompletionStage;
import java.util.concurrent.TimeUnit;
import org.junit.jupiter.api.AfterAll;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.BeforeAll;
Expand Down Expand Up @@ -530,11 +530,11 @@ private static void testLogRecordExporter(LogRecordExporter logRecordExporter) {
try (Scope unused = Span.wrap(spanContext).makeCurrent()) {
logger
.logRecordBuilder()
.setTimestamp(100, TimeUnit.NANOSECONDS)
.setBody("log body")
.setAllAttributes(Attributes.builder().put("key", "value").build())
.setSeverity(Severity.DEBUG)
.setSeverityText("DEBUG")
.setTimestamp(Instant.now())
.setContext(Context.current())
.emit();
eventEmitter.emit("event-name", Attributes.builder().put("key", "value").build());
Expand Down Expand Up @@ -582,7 +582,7 @@ private static void testLogRecordExporter(LogRecordExporter logRecordExporter) {
.isEqualTo(spanContext.getSpanId());
assertThat(TraceFlags.fromByte((byte) protoLog1.getFlags()))
.isEqualTo(spanContext.getTraceFlags());
assertThat(protoLog1.getTimeUnixNano()).isGreaterThan(0);
assertThat(protoLog1.getTimeUnixNano()).isEqualTo(100);

// LogRecord via EventEmitter.emit(String, Attributes)
io.opentelemetry.proto.logs.v1.LogRecord protoLog2 = ilLogs.getLogRecords(1);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,8 @@
import io.opentelemetry.api.logs.Logger;
import io.opentelemetry.api.logs.LoggerBuilder;
import io.opentelemetry.api.logs.LoggerProvider;
import io.opentelemetry.sdk.common.Clock;
import java.util.concurrent.TimeUnit;

/**
* SDK implementation for {@link EventEmitterProvider}.
Expand All @@ -25,16 +27,25 @@ public final class SdkEventEmitterProvider implements EventEmitterProvider {
private static final String DEFAULT_EVENT_DOMAIN = "unknown";

private final LoggerProvider delegateLoggerProvider;
private final Clock clock;

private SdkEventEmitterProvider(LoggerProvider delegateLoggerProvider) {
private SdkEventEmitterProvider(LoggerProvider delegateLoggerProvider, Clock clock) {
this.delegateLoggerProvider = delegateLoggerProvider;
this.clock = clock;
}

/**
* Create a {@link SdkEventEmitterProvider} which delegates to the {@code delegateLoggerProvider}.
*/
public static SdkEventEmitterProvider create(LoggerProvider delegateLoggerProvider) {
return new SdkEventEmitterProvider(delegateLoggerProvider);
return new SdkEventEmitterProvider(delegateLoggerProvider, Clock.getDefault());
}

/**
* Create a {@link SdkEventEmitterProvider} which delegates to the {@code delegateLoggerProvider}.
*/
public static SdkEventEmitterProvider create(LoggerProvider delegateLoggerProvider, Clock clock) {
return new SdkEventEmitterProvider(delegateLoggerProvider, clock);
}

@Override
Expand All @@ -47,15 +58,17 @@ public EventEmitter get(String instrumentationScopeName) {
@Override
public EventEmitterBuilder eventEmitterBuilder(String instrumentationScopeName) {
return new SdkEventEmitterBuilder(
delegateLoggerProvider.loggerBuilder(instrumentationScopeName));
clock, delegateLoggerProvider.loggerBuilder(instrumentationScopeName));
}

private static class SdkEventEmitterBuilder implements EventEmitterBuilder {

private final Clock clock;
private final LoggerBuilder delegateLoggerBuilder;
private String eventDomain = DEFAULT_EVENT_DOMAIN;

private SdkEventEmitterBuilder(LoggerBuilder delegateLoggerBuilder) {
private SdkEventEmitterBuilder(Clock clock, LoggerBuilder delegateLoggerBuilder) {
this.clock = clock;
this.delegateLoggerBuilder = delegateLoggerBuilder;
}

Expand All @@ -79,7 +92,7 @@ public EventEmitterBuilder setInstrumentationVersion(String instrumentationScope

@Override
public EventEmitter build() {
return new SdkEventEmitter(delegateLoggerBuilder.build(), eventDomain);
return new SdkEventEmitter(clock, delegateLoggerBuilder.build(), eventDomain);
}
}

Expand All @@ -88,10 +101,12 @@ private static class SdkEventEmitter implements EventEmitter {
private static final AttributeKey<String> EVENT_DOMAIN = AttributeKey.stringKey("event.domain");
private static final AttributeKey<String> EVENT_NAME = AttributeKey.stringKey("event.name");

private final Clock clock;
private final Logger delegateLogger;
private final String eventDomain;

private SdkEventEmitter(Logger delegateLogger, String eventDomain) {
private SdkEventEmitter(Clock clock, Logger delegateLogger, String eventDomain) {
this.clock = clock;
this.delegateLogger = delegateLogger;
this.eventDomain = eventDomain;
}
Expand All @@ -100,6 +115,7 @@ private SdkEventEmitter(Logger delegateLogger, String eventDomain) {
public void emit(String eventName, Attributes attributes) {
delegateLogger
.logRecordBuilder()
.setTimestamp(clock.now(), TimeUnit.NANOSECONDS)
.setAllAttributes(attributes)
.setAttribute(EVENT_DOMAIN, eventDomain)
.setAttribute(EVENT_NAME, eventName)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -103,9 +103,7 @@ public void emit() {
loggerSharedState.getLogLimits(),
loggerSharedState.getResource(),
instrumentationScopeInfo,
this.timestampEpochNanos == 0
? this.loggerSharedState.getClock().now()
: this.timestampEpochNanos,
this.timestampEpochNanos,
Span.fromContext(context).getSpanContext(),
severity,
severityText,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -72,11 +72,7 @@ public SdkLoggerProviderBuilder addLogRecordProcessor(LogRecordProcessor process
}

/**
* Assign a {@link Clock}. The {@link Clock} may be used to determine "now" in the event that the
* epoch millis are not set directly.
*
* <p>The {@code clock} must be thread-safe and return immediately (no remote calls, as contention
* free as possible).
* Assign a {@link Clock}.
*
* @param clock The clock to use for all temporal needs.
* @return this
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,8 +6,11 @@
package io.opentelemetry.sdk.logs;

import static io.opentelemetry.sdk.testing.assertj.LogAssertions.assertThat;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.when;

import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.sdk.common.Clock;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.resources.Resource;
import java.util.concurrent.atomic.AtomicReference;
Expand All @@ -18,16 +21,20 @@ class SdkEventEmitterProviderTest {
private static final Resource RESOURCE =
Resource.builder().put("resource-key", "resource-value").build();

private final Clock clock = mock(Clock.class);
private final AtomicReference<ReadWriteLogRecord> seenLog = new AtomicReference<>();
private final SdkEventEmitterProvider eventEmitterProvider =
SdkEventEmitterProvider.create(
SdkLoggerProvider.builder()
.setResource(RESOURCE)
.addLogRecordProcessor((context, logRecord) -> seenLog.set(logRecord))
.build());
.build(),
clock);

@Test
void emit_WithDomain() {
when(clock.now()).thenReturn(10L);

eventEmitterProvider
.eventEmitterBuilder("test-scope")
.setEventDomain("event-domain")
Expand All @@ -45,6 +52,7 @@ void emit_WithDomain() {
assertThat(seenLog.get().toLogRecordData())
.hasResource(RESOURCE)
.hasInstrumentationScope(InstrumentationScopeInfo.create("test-scope"))
.hasTimestamp(10L)
.hasAttributes(
Attributes.builder()
.put("key1", "value1")
Expand All @@ -55,6 +63,8 @@ void emit_WithDomain() {

@Test
void emit_NoDomain() {
when(clock.now()).thenReturn(10L);

eventEmitterProvider
.eventEmitterBuilder("test-scope")
.build()
Expand All @@ -71,6 +81,7 @@ void emit_NoDomain() {
assertThat(seenLog.get().toLogRecordData())
.hasResource(RESOURCE)
.hasInstrumentationScope(InstrumentationScopeInfo.create("test-scope"))
.hasTimestamp(10L)
.hasAttributes(
Attributes.builder()
.put("key1", "value1")
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,6 @@
package io.opentelemetry.sdk.logs;

import static io.opentelemetry.sdk.testing.assertj.LogAssertions.assertThat;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.when;

import io.opentelemetry.api.common.AttributeKey;
Expand All @@ -17,7 +16,6 @@
import io.opentelemetry.api.trace.TraceFlags;
import io.opentelemetry.api.trace.TraceState;
import io.opentelemetry.context.Context;
import io.opentelemetry.sdk.common.Clock;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.Body;
import io.opentelemetry.sdk.resources.Resource;
Expand Down Expand Up @@ -50,7 +48,6 @@ void setup() {
when(loggerSharedState.getLogRecordProcessor())
.thenReturn((context, logRecord) -> emittedLog.set(logRecord));
when(loggerSharedState.getResource()).thenReturn(RESOURCE);
when(loggerSharedState.getClock()).thenReturn(Clock.getDefault());

builder = new SdkLogRecordBuilder(loggerSharedState, SCOPE_INFO);
}
Expand Down Expand Up @@ -92,17 +89,13 @@ void emit_AllFields() {

@Test
void emit_NoFields() {
Clock clock = mock(Clock.class);
when(clock.now()).thenReturn(10L);
when(loggerSharedState.getClock()).thenReturn(clock);

builder.emit();

assertThat(emittedLog.get().toLogRecordData())
.hasResource(RESOURCE)
.hasInstrumentationScope(SCOPE_INFO)
.hasBody(Body.empty().asString())
.hasTimestamp(10L)
.hasTimestamp(0L)
.hasAttributes(Attributes.empty())
.hasSpanContext(SpanContext.getInvalid())
.hasSeverity(Severity.UNDEFINED_SEVERITY_NUMBER);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -30,8 +30,6 @@
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.LogRecordData;
import io.opentelemetry.sdk.resources.Resource;
import java.util.ArrayList;
import java.util.List;
import java.util.Optional;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicReference;
Expand Down Expand Up @@ -333,23 +331,6 @@ void close() {
verify(logRecordProcessor).shutdown();
}

@Test
void canSetClock() {
long now = TimeUnit.MILLISECONDS.toNanos(System.currentTimeMillis());
Clock clock = mock(Clock.class);
when(clock.now()).thenReturn(now);
List<ReadWriteLogRecord> seenLogs = new ArrayList<>();
logRecordProcessor = (context, logRecord) -> seenLogs.add(logRecord);
sdkLoggerProvider =
SdkLoggerProvider.builder()
.setClock(clock)
.addLogRecordProcessor(logRecordProcessor)
.build();
sdkLoggerProvider.loggerBuilder(null).build().logRecordBuilder().emit();
assertThat(seenLogs.size()).isEqualTo(1);
assertThat(seenLogs.get(0).toLogRecordData().getTimestampEpochNanos()).isEqualTo(now);
}

@Test
void toString_Valid() {
when(logRecordProcessor.toString()).thenReturn("MockLogRecordProcessor");
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,6 @@ void logRecordBuilder() {
AtomicReference<ReadWriteLogRecord> seenLog = new AtomicReference<>();
LogRecordProcessor logRecordProcessor = (context, logRecord) -> seenLog.set(logRecord);
Clock clock = mock(Clock.class);
when(clock.now()).thenReturn(5L);

when(state.getResource()).thenReturn(Resource.getDefault());
when(state.getLogRecordProcessor()).thenReturn(logRecordProcessor);
Expand All @@ -52,7 +51,7 @@ void logRecordBuilder() {

// Have to test through the builder
logRecordBuilder.emit();
assertThat(seenLog.get().toLogRecordData()).hasBody("foo").hasTimestamp(5);
assertThat(seenLog.get().toLogRecordData()).hasBody("foo").hasTimestamp(0);
}

@Test
Expand Down

0 comments on commit cbbba71

Please sign in to comment.