Skip to content

Commit

Permalink
Remove TimeExtractor and use internal API for setting start/end times…
Browse files Browse the repository at this point in the history
…tamps (#6051)

* Remove TimeExtractor and use internal API for setting start/end timestamps

* code review comments
  • Loading branch information
Mateusz Rzeszutek authored May 19, 2022
1 parent a2a8c11 commit 512a040
Show file tree
Hide file tree
Showing 34 changed files with 244 additions and 415 deletions.
35 changes: 0 additions & 35 deletions docs/contributing/using-instrumenter-api.md
Original file line number Diff line number Diff line change
Expand Up @@ -319,41 +319,6 @@ default `jdk()` implementation that removes the known JDK wrapper exception type
You can set the `ErrorCauseExtractor` in the `InstrumenterBuilder` using
the `setErrorCauseExtractor()` method.

### Provide custom operation start and end times using the `TimeExtractor`

In some cases, the instrumented library provides a way to retrieve accurate timestamps of when the
operation starts and ends. The `TimeExtractor` interface can be used to
feed this information into OpenTelemetry trace and metrics data.

`extractStartTime()` can only extract the timestamp from the request. `extractEndTime()`
accepts the request, an optional response, and an optional `Throwable` error. Consider the following
example:

```java
class MyTimeExtractor implements TimeExtractor<Request, Response> {

@Override
public Instant extractStartTime(Request request) {
return request.startTimestamp();
}

@Override
public Instant extractEndTime(Request request, @Nullable Response response, @Nullable Throwable error) {
if (response != null) {
return response.endTimestamp();
}
return request.clock().now();
}
}
```

The sample implementations above use the request to retrieve the start timestamp. The response is
used to compute the end time if it is available; in case it is missing (for example, when an error
occurs) the same time source is used to compute the current timestamp.

You can set the time extractor in the `InstrumenterBuilder` using the `setTimeExtractor()`
method.

### Register metrics by implementing the `OperationMetrics` and `OperationListener`

If you need to add metrics to the `Instrumenter` you can implement the `OperationMetrics`
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -76,7 +76,6 @@ public static <REQUEST, RESPONSE> InstrumenterBuilder<REQUEST, RESPONSE> builder
private final List<? extends ContextCustomizer<? super REQUEST>> contextCustomizers;
private final List<? extends OperationListener> operationListeners;
private final ErrorCauseExtractor errorCauseExtractor;
@Nullable private final TimeExtractor<REQUEST, RESPONSE> timeExtractor;
private final boolean enabled;
private final SpanSuppressor spanSuppressor;

Expand All @@ -91,7 +90,6 @@ public static <REQUEST, RESPONSE> InstrumenterBuilder<REQUEST, RESPONSE> builder
this.contextCustomizers = new ArrayList<>(builder.contextCustomizers);
this.operationListeners = builder.buildOperationListeners();
this.errorCauseExtractor = builder.errorCauseExtractor;
this.timeExtractor = builder.timeExtractor;
this.enabled = builder.enabled;
this.spanSuppressor = builder.buildSpanSuppressor();
}
Expand Down Expand Up @@ -129,16 +127,46 @@ public boolean shouldStart(Context parentContext, REQUEST request) {
* object of this operation.
*/
public Context start(Context parentContext, REQUEST request) {
return doStart(parentContext, request, null);
}

/**
* Ends an instrumented operation. It is of extreme importance for this method to be always called
* after {@link #start(Context, Object) start()}. Calling {@code start()} without later {@code
* end()} will result in inaccurate or wrong telemetry and context leaks.
*
* <p>The {@code context} must be the same value that was returned from {@link #start(Context,
* Object)}. The {@code request} parameter is the request object of the operation, {@code
* response} is the response object of the operation, and {@code error} is an exception that was
* thrown by the operation or {@code null} if no error occurred.
*/
public void end(
Context context, REQUEST request, @Nullable RESPONSE response, @Nullable Throwable error) {
doEnd(context, request, response, error, null);
}

/** Internal method for creating spans with given start/end timestamps. */
Context startAndEnd(
Context parentContext,
REQUEST request,
@Nullable RESPONSE response,
@Nullable Throwable error,
Instant startTime,
Instant endTime) {
Context context = doStart(parentContext, request, startTime);
doEnd(context, request, response, error, endTime);
return context;
}

private Context doStart(Context parentContext, REQUEST request, @Nullable Instant startTime) {
SpanKind spanKind = spanKindExtractor.extract(request);
SpanBuilder spanBuilder =
tracer
.spanBuilder(spanNameExtractor.extract(request))
.setSpanKind(spanKind)
.setParent(parentContext);

Instant startTime = null;
if (timeExtractor != null) {
startTime = timeExtractor.extractStartTime(request);
if (startTime != null) {
spanBuilder.setStartTimestamp(startTime);
}

Expand Down Expand Up @@ -176,18 +204,12 @@ public Context start(Context parentContext, REQUEST request) {
return spanSuppressor.storeInContext(context, spanKind, span);
}

/**
* Ends an instrumented operation. It is of extreme importance for this method to be always called
* after {@link #start(Context, Object) start()}. Calling {@code start()} without later {@code
* end()} will result in inaccurate or wrong telemetry and context leaks.
*
* <p>The {@code context} must be the same value that was returned from {@link #start(Context,
* Object)}. The {@code request} parameter is the request object of the operation, {@code
* response} is the response object of the operation, and {@code error} is an exception that was
* thrown by the operation or {@code null} if no error occurred.
*/
public void end(
Context context, REQUEST request, @Nullable RESPONSE response, @Nullable Throwable error) {
private void doEnd(
Context context,
REQUEST request,
@Nullable RESPONSE response,
@Nullable Throwable error,
@Nullable Instant endTime) {
Span span = Span.fromContext(context);

if (error != null) {
Expand All @@ -201,11 +223,6 @@ public void end(
}
span.setAllAttributes(attributes);

Instant endTime = null;
if (timeExtractor != null) {
endTime = timeExtractor.extractEndTime(request, response, error);
}

if (!operationListeners.isEmpty()) {
long endNanos = getNanos(endTime);
ListIterator<? extends OperationListener> i =
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,6 @@

package io.opentelemetry.instrumentation.api.instrumenter;

import static java.util.Objects.requireNonNull;

import io.opentelemetry.api.OpenTelemetry;
import io.opentelemetry.api.metrics.Meter;
import io.opentelemetry.api.metrics.MeterBuilder;
Expand Down Expand Up @@ -57,7 +55,6 @@ public final class InstrumenterBuilder<REQUEST, RESPONSE> {
SpanStatusExtractor<? super REQUEST, ? super RESPONSE> spanStatusExtractor =
SpanStatusExtractor.getDefault();
ErrorCauseExtractor errorCauseExtractor = ErrorCauseExtractor.jdk();
@Nullable TimeExtractor<REQUEST, RESPONSE> timeExtractor = null;
boolean enabled = true;

InstrumenterBuilder(
Expand Down Expand Up @@ -181,10 +178,12 @@ public InstrumenterBuilder<REQUEST, RESPONSE> setErrorCauseExtractor(
* {@link TimeExtractor} will be used to generate any duration metrics, but the internal metric
* timestamp (when it occurred) will always be stamped with "now" when the metric is recorded
* (i.e. there is no way to back date a metric recording).
*
* @deprecated Setting operation start and end times is not currently supported.
*/
@Deprecated
public InstrumenterBuilder<REQUEST, RESPONSE> setTimeExtractor(
TimeExtractor<REQUEST, RESPONSE> timeExtractor) {
this.timeExtractor = requireNonNull(timeExtractor);
return this;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,10 @@
* {@link TimeExtractor} will be used to generate any duration metrics, but the internal metric
* timestamp (when it occurred) will always be stamped with "now" when the metric is recorded (i.e.
* there is no way to back date a metric recording).
*
* @deprecated Setting operation start and end times is not currently supported.
*/
@Deprecated
public interface TimeExtractor<REQUEST, RESPONSE> {

/** Returns the timestamp marking the start of the request processing. */
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,71 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.api.internal;

import io.opentelemetry.context.Context;
import io.opentelemetry.instrumentation.api.instrumenter.Instrumenter;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.time.Instant;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.annotation.Nullable;

/**
* This class is internal and is hence not for public use. Its APIs are unstable and can change at
* any time.
*/
public final class InstrumenterUtil {

private static final Logger logger = Logger.getLogger(InstrumenterUtil.class.getName());

private static final Method startAndEndMethod;

static {
Method method = null;
try {
method =
Instrumenter.class.getDeclaredMethod(
"startAndEnd",
Context.class,
Object.class,
Object.class,
Throwable.class,
Instant.class,
Instant.class);
method.setAccessible(true);
} catch (NoSuchMethodException e) {
logger.log(
Level.WARNING, "Could not get Instrumenter#startAndEnd() method with reflection", e);
}
startAndEndMethod = method;
}

public static <REQUEST, RESPONSE> Context startAndEnd(
Instrumenter<REQUEST, RESPONSE> instrumenter,
Context parentContext,
REQUEST request,
@Nullable RESPONSE response,
@Nullable Throwable error,
Instant startTime,
Instant endTime) {

if (startAndEndMethod == null) {
// already logged a warning when this class initialized
return parentContext;
}
try {
return (Context)
startAndEndMethod.invoke(
instrumenter, parentContext, request, response, error, startTime, endTime);
} catch (InvocationTargetException | IllegalAccessException e) {
logger.log(Level.WARNING, "Error occurred when calling Instrumenter#startAndEnd()", e);
return parentContext;
}
}

private InstrumenterUtil() {}
}
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,6 @@
import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension;
import io.opentelemetry.sdk.trace.data.LinkData;
import io.opentelemetry.sdk.trace.data.StatusData;
import java.time.Instant;
import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
Expand Down Expand Up @@ -126,20 +125,6 @@ public void extract(
}
}

static class TestTimeExtractor implements TimeExtractor<Instant, Instant> {

@Override
public Instant extractStartTime(Instant request) {
return request;
}

@Override
public Instant extractEndTime(
Instant request, @Nullable Instant response, @Nullable Throwable error) {
return response;
}
}

static class MapGetter implements TextMapGetter<Map<String, String>> {

@Override
Expand Down Expand Up @@ -439,31 +424,6 @@ public void onEnd(Context context, Attributes endAttributes, long endNanos) {
assertThat(Span.fromContext(endContext.get()).getSpanContext().isValid()).isTrue();
}

@Test
void shouldStartSpanWithGivenStartTime() {
// given
Instrumenter<Instant, Instant> instrumenter =
Instrumenter.<Instant, Instant>builder(
otelTesting.getOpenTelemetry(), "test", request -> "test span")
.setTimeExtractor(new TestTimeExtractor())
.newInstrumenter();

Instant startTime = Instant.ofEpochSecond(100);
Instant endTime = Instant.ofEpochSecond(123);

// when
Context context = instrumenter.start(Context.root(), startTime);
instrumenter.end(context, startTime, endTime, null);

// then
otelTesting
.assertTraces()
.hasTracesSatisfyingExactly(
trace ->
trace.hasSpansSatisfyingExactly(
span -> span.hasName("test span").startsAt(startTime).endsAt(endTime)));
}

@Test
void shouldNotAddInvalidLink() {
// given
Expand Down
Loading

0 comments on commit 512a040

Please sign in to comment.