Fix exemplars (#4678)

This commit is contained in:
Trask Stalnaker 2021-11-20 10:42:06 -08:00 committed by GitHub
parent 5b88f1bf05
commit 260c603784
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
7 changed files with 132 additions and 38 deletions

View File

@ -100,6 +100,7 @@ public class Instrumenter<REQUEST, RESPONSE> {
attributesExtractors; attributesExtractors;
private final List<? extends ContextCustomizer<? super REQUEST>> contextCustomizers; private final List<? extends ContextCustomizer<? super REQUEST>> contextCustomizers;
private final List<? extends RequestListener> requestListeners; private final List<? extends RequestListener> requestListeners;
private final List<? extends RequestListener> requestMetricListeners;
private final ErrorCauseExtractor errorCauseExtractor; private final ErrorCauseExtractor errorCauseExtractor;
@Nullable private final StartTimeExtractor<REQUEST> startTimeExtractor; @Nullable private final StartTimeExtractor<REQUEST> startTimeExtractor;
@Nullable private final EndTimeExtractor<REQUEST, RESPONSE> endTimeExtractor; @Nullable private final EndTimeExtractor<REQUEST, RESPONSE> endTimeExtractor;
@ -117,6 +118,7 @@ public class Instrumenter<REQUEST, RESPONSE> {
this.attributesExtractors = new ArrayList<>(builder.attributesExtractors); this.attributesExtractors = new ArrayList<>(builder.attributesExtractors);
this.contextCustomizers = new ArrayList<>(builder.contextCustomizers); this.contextCustomizers = new ArrayList<>(builder.contextCustomizers);
this.requestListeners = new ArrayList<>(builder.requestListeners); this.requestListeners = new ArrayList<>(builder.requestListeners);
this.requestMetricListeners = new ArrayList<>(builder.requestMetricListeners);
this.errorCauseExtractor = builder.errorCauseExtractor; this.errorCauseExtractor = builder.errorCauseExtractor;
this.startTimeExtractor = builder.startTimeExtractor; this.startTimeExtractor = builder.startTimeExtractor;
this.endTimeExtractor = builder.endTimeExtractor; this.endTimeExtractor = builder.endTimeExtractor;
@ -192,6 +194,15 @@ public class Instrumenter<REQUEST, RESPONSE> {
Span span = spanBuilder.startSpan(); Span span = spanBuilder.startSpan();
context = context.with(span); context = context.with(span);
// request metric listeners need to run after the span has been added to the context in order
// for them to generate exemplars
if (!requestMetricListeners.isEmpty()) {
long startNanos = getNanos(startTime);
for (RequestListener requestListener : requestMetricListeners) {
context = requestListener.start(context, attributes, startNanos);
}
}
return spanSuppressionStrategy.storeInContext(context, spanKind, span); return spanSuppressionStrategy.storeInContext(context, spanKind, span);
} }
@ -221,11 +232,14 @@ public class Instrumenter<REQUEST, RESPONSE> {
endTime = endTimeExtractor.extract(request, response, error); endTime = endTimeExtractor.extract(request, response, error);
} }
if (!requestListeners.isEmpty()) { if (!requestListeners.isEmpty() || !requestMetricListeners.isEmpty()) {
long endNanos = getNanos(endTime); long endNanos = getNanos(endTime);
for (RequestListener requestListener : requestListeners) { for (RequestListener requestListener : requestListeners) {
requestListener.end(context, attributes, endNanos); requestListener.end(context, attributes, endNanos);
} }
for (RequestListener requestListener : requestMetricListeners) {
requestListener.end(context, attributes, endNanos);
}
} }
StatusCode statusCode = spanStatusExtractor.extract(request, response, error); StatusCode statusCode = spanStatusExtractor.extract(request, response, error);

View File

@ -50,6 +50,7 @@ public final class InstrumenterBuilder<REQUEST, RESPONSE> {
new ArrayList<>(); new ArrayList<>();
final List<ContextCustomizer<? super REQUEST>> contextCustomizers = new ArrayList<>(); final List<ContextCustomizer<? super REQUEST>> contextCustomizers = new ArrayList<>();
final List<RequestListener> requestListeners = new ArrayList<>(); final List<RequestListener> requestListeners = new ArrayList<>();
final List<RequestListener> requestMetricListeners = new ArrayList<>();
SpanKindExtractor<? super REQUEST> spanKindExtractor = SpanKindExtractor.alwaysInternal(); SpanKindExtractor<? super REQUEST> spanKindExtractor = SpanKindExtractor.alwaysInternal();
SpanStatusExtractor<? super REQUEST, ? super RESPONSE> spanStatusExtractor = SpanStatusExtractor<? super REQUEST, ? super RESPONSE> spanStatusExtractor =
@ -124,7 +125,7 @@ public final class InstrumenterBuilder<REQUEST, RESPONSE> {
/** Adds a {@link RequestMetrics} whose metrics will be recorded for request start and stop. */ /** Adds a {@link RequestMetrics} whose metrics will be recorded for request start and stop. */
@UnstableApi @UnstableApi
public InstrumenterBuilder<REQUEST, RESPONSE> addRequestMetrics(RequestMetrics factory) { public InstrumenterBuilder<REQUEST, RESPONSE> addRequestMetrics(RequestMetrics factory) {
requestListeners.add(factory.create(meter)); requestMetricListeners.add(factory.create(meter));
return this; return this;
} }

View File

@ -76,7 +76,8 @@ public final class HttpClientMetrics implements RequestListener {
} }
duration.record( duration.record(
(endNanos - state.startTimeNanos()) / NANOS_PER_MS, (endNanos - state.startTimeNanos()) / NANOS_PER_MS,
applyClientDurationView(state.startAttributes(), endAttributes)); applyClientDurationView(state.startAttributes(), endAttributes),
context);
} }
@AutoValue @AutoValue

View File

@ -71,7 +71,7 @@ public final class HttpServerMetrics implements RequestListener {
@Override @Override
public Context start(Context context, Attributes startAttributes, long startNanos) { public Context start(Context context, Attributes startAttributes, long startNanos) {
activeRequests.add(1, applyActiveRequestsView(startAttributes)); activeRequests.add(1, applyActiveRequestsView(startAttributes), context);
return context.with( return context.with(
HTTP_SERVER_REQUEST_METRICS_STATE, HTTP_SERVER_REQUEST_METRICS_STATE,
@ -89,7 +89,8 @@ public final class HttpServerMetrics implements RequestListener {
activeRequests.add(-1, applyActiveRequestsView(state.startAttributes())); activeRequests.add(-1, applyActiveRequestsView(state.startAttributes()));
duration.record( duration.record(
(endNanos - state.startTimeNanos()) / NANOS_PER_MS, (endNanos - state.startTimeNanos()) / NANOS_PER_MS,
applyServerDurationView(state.startAttributes(), endAttributes)); applyServerDurationView(state.startAttributes(), endAttributes),
context);
} }
@AutoValue @AutoValue

View File

@ -10,6 +10,7 @@ import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.attri
import static org.assertj.core.api.Assertions.entry; import static org.assertj.core.api.Assertions.entry;
import static org.mockito.Mockito.when; import static org.mockito.Mockito.when;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.common.AttributesBuilder; import io.opentelemetry.api.common.AttributesBuilder;
import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.api.trace.SpanContext;
@ -39,6 +40,7 @@ import java.time.Instant;
import java.util.Collections; import java.util.Collections;
import java.util.HashMap; import java.util.HashMap;
import java.util.Map; import java.util.Map;
import java.util.concurrent.atomic.AtomicReference;
import java.util.stream.Collectors; import java.util.stream.Collectors;
import java.util.stream.Stream; import java.util.stream.Stream;
import javax.annotation.Nullable; import javax.annotation.Nullable;
@ -410,6 +412,38 @@ class InstrumenterTest {
.hasParentSpanId("090a0b0c0d0e0f00"))); .hasParentSpanId("090a0b0c0d0e0f00")));
} }
@Test
void requestMetrics() {
AtomicReference<Context> startContext = new AtomicReference<>();
AtomicReference<Context> endContext = new AtomicReference<>();
RequestListener requestListener =
new RequestListener() {
@Override
public Context start(Context context, Attributes startAttributes, long startNanos) {
startContext.set(context);
return context;
}
@Override
public void end(Context context, Attributes endAttributes, long endNanos) {
endContext.set(context);
}
};
Instrumenter<Map<String, String>, Map<String, String>> instrumenter =
Instrumenter.<Map<String, String>, Map<String, String>>builder(
otelTesting.getOpenTelemetry(), "test", unused -> "span")
.addRequestMetrics(meter -> requestListener)
.newServerInstrumenter(new MapGetter());
Context context = instrumenter.start(Context.root(), REQUEST);
instrumenter.end(context, REQUEST, RESPONSE, null);
assertThat(Span.fromContext(startContext.get()).getSpanContext().isValid()).isTrue();
assertThat(Span.fromContext(endContext.get()).getSpanContext().isValid()).isTrue();
}
@Test @Test
void shouldStartSpanWithGivenStartTime() { void shouldStartSpanWithGivenStartTime() {
// given // given

View File

@ -10,6 +10,10 @@ import static io.opentelemetry.sdk.testing.assertj.metrics.MetricAssertions.asse
import static org.awaitility.Awaitility.await; import static org.awaitility.Awaitility.await;
import io.opentelemetry.api.common.Attributes; import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.api.trace.TraceFlags;
import io.opentelemetry.api.trace.TraceState;
import io.opentelemetry.context.Context; import io.opentelemetry.context.Context;
import io.opentelemetry.instrumentation.api.instrumenter.RequestListener; import io.opentelemetry.instrumentation.api.instrumenter.RequestListener;
import io.opentelemetry.sdk.metrics.SdkMeterProvider; import io.opentelemetry.sdk.metrics.SdkMeterProvider;
@ -47,7 +51,17 @@ class HttpClientMetricsTest {
.put("http.status_code", 200) .put("http.status_code", 200)
.build(); .build();
Context context1 = listener.start(Context.current(), requestAttributes, nanos(100)); Context parent =
Context.root()
.with(
Span.wrap(
SpanContext.create(
"ff01020304050600ff0a0b0c0d0e0f00",
"090a0b0c0d0e0f00",
TraceFlags.getSampled(),
TraceState.getDefault())));
Context context1 = listener.start(parent, requestAttributes, nanos(100));
// TODO(anuraaga): Remove await from this file after 1.8.0 hopefully fixes // TODO(anuraaga): Remove await from this file after 1.8.0 hopefully fixes
// https://github.com/open-telemetry/opentelemetry-java/issues/3725 // https://github.com/open-telemetry/opentelemetry-java/issues/3725
@ -58,7 +72,7 @@ class HttpClientMetricsTest {
assertThat(metrics).isEmpty(); assertThat(metrics).isEmpty();
}); });
Context context2 = listener.start(Context.current(), requestAttributes, nanos(150)); Context context2 = listener.start(Context.root(), requestAttributes, nanos(150));
await() await()
.untilAsserted( .untilAsserted(
@ -82,7 +96,7 @@ class HttpClientMetricsTest {
.hasDoubleHistogram() .hasDoubleHistogram()
.points() .points()
.satisfiesExactly( .satisfiesExactly(
point -> point -> {
assertThat(point) assertThat(point)
.hasSum(150 /* millis */) .hasSum(150 /* millis */)
.attributes() .attributes()
@ -90,7 +104,12 @@ class HttpClientMetricsTest {
attributeEntry("http.url", "https://localhost:1234/"), attributeEntry("http.url", "https://localhost:1234/"),
attributeEntry("http.method", "GET"), attributeEntry("http.method", "GET"),
attributeEntry("http.flavor", "2.0"), attributeEntry("http.flavor", "2.0"),
attributeEntry("http.status_code", 200)))); attributeEntry("http.status_code", 200));
assertThat(point).exemplars().hasSize(1);
assertThat(point.getExemplars().get(0))
.hasTraceId("ff01020304050600ff0a0b0c0d0e0f00")
.hasSpanId("090a0b0c0d0e0f00");
}));
}); });
listener.end(context2, responseAttributes, nanos(300)); listener.end(context2, responseAttributes, nanos(300));

View File

@ -10,6 +10,10 @@ import static io.opentelemetry.sdk.testing.assertj.metrics.MetricAssertions.asse
import static org.awaitility.Awaitility.await; import static org.awaitility.Awaitility.await;
import io.opentelemetry.api.common.Attributes; import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.api.trace.TraceFlags;
import io.opentelemetry.api.trace.TraceState;
import io.opentelemetry.context.Context; import io.opentelemetry.context.Context;
import io.opentelemetry.instrumentation.api.instrumenter.RequestListener; import io.opentelemetry.instrumentation.api.instrumenter.RequestListener;
import io.opentelemetry.sdk.metrics.SdkMeterProvider; import io.opentelemetry.sdk.metrics.SdkMeterProvider;
@ -23,7 +27,7 @@ class HttpServerMetricsTest {
@Test @Test
void collectsMetrics() { void collectsMetrics() {
InMemoryMetricReader metricReader = new InMemoryMetricReader(); InMemoryMetricReader metricReader = InMemoryMetricReader.create();
SdkMeterProvider meterProvider = SdkMeterProvider meterProvider =
SdkMeterProvider.builder().registerMetricReader(metricReader).build(); SdkMeterProvider.builder().registerMetricReader(metricReader).build();
@ -46,7 +50,17 @@ class HttpServerMetricsTest {
.put("http.status_code", 200) .put("http.status_code", 200)
.build(); .build();
Context context1 = listener.start(Context.current(), requestAttributes, nanos(100)); Context parent =
Context.root()
.with(
Span.wrap(
SpanContext.create(
"ff01020304050600ff0a0b0c0d0e0f00",
"090a0b0c0d0e0f00",
TraceFlags.getSampled(),
TraceState.getDefault())));
Context context1 = listener.start(parent, requestAttributes, nanos(100));
// TODO(anuraaga): Remove await from this file after 1.8.0 hopefully fixes // TODO(anuraaga): Remove await from this file after 1.8.0 hopefully fixes
// https://github.com/open-telemetry/opentelemetry-java/issues/3725 // https://github.com/open-telemetry/opentelemetry-java/issues/3725
@ -66,17 +80,22 @@ class HttpServerMetricsTest {
.hasLongSum() .hasLongSum()
.points() .points()
.satisfiesExactly( .satisfiesExactly(
point -> point -> {
assertThat(point) assertThat(point)
.hasValue(1) .hasValue(1)
.attributes() .attributes()
.containsOnly( .containsOnly(
attributeEntry("http.host", "host"), attributeEntry("http.host", "host"),
attributeEntry("http.method", "GET"), attributeEntry("http.method", "GET"),
attributeEntry("http.scheme", "https")))); attributeEntry("http.scheme", "https"));
assertThat(point).exemplars().hasSize(1);
assertThat(point.getExemplars().get(0))
.hasTraceId("ff01020304050600ff0a0b0c0d0e0f00")
.hasSpanId("090a0b0c0d0e0f00");
}));
}); });
Context context2 = listener.start(Context.current(), requestAttributes, nanos(150)); Context context2 = listener.start(Context.root(), requestAttributes, nanos(150));
await() await()
.untilAsserted( .untilAsserted(
@ -116,7 +135,7 @@ class HttpServerMetricsTest {
.hasDoubleHistogram() .hasDoubleHistogram()
.points() .points()
.satisfiesExactly( .satisfiesExactly(
point -> point -> {
assertThat(point) assertThat(point)
.hasSum(150 /* millis */) .hasSum(150 /* millis */)
.attributes() .attributes()
@ -126,7 +145,12 @@ class HttpServerMetricsTest {
attributeEntry("http.target", "/"), attributeEntry("http.target", "/"),
attributeEntry("http.method", "GET"), attributeEntry("http.method", "GET"),
attributeEntry("http.status_code", 200), attributeEntry("http.status_code", 200),
attributeEntry("http.flavor", "2.0")))); attributeEntry("http.flavor", "2.0"));
assertThat(point).exemplars().hasSize(1);
assertThat(point.getExemplars().get(0))
.hasTraceId("ff01020304050600ff0a0b0c0d0e0f00")
.hasSpanId("090a0b0c0d0e0f00");
}));
}); });
listener.end(context2, responseAttributes, nanos(300)); listener.end(context2, responseAttributes, nanos(300));