-
Notifications
You must be signed in to change notification settings - Fork 845
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
[On Hold] Improve behavior of un-ended ReadableSpan #693
Changes from all commits
6de98a6
b3e419a
346a47b
3688ccb
95ec8b0
07e7a3b
9875df5
d3153a3
997aaf8
425edcc
a030e1b
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -98,7 +98,7 @@ final class RecordEventsReadableSpan implements ReadableSpan, Span { | |
private long endEpochNanos; | ||
// True if the span is ended. | ||
@GuardedBy("lock") | ||
private boolean hasBeenEnded; | ||
private boolean hasEnded; | ||
|
||
/** | ||
* Creates and starts a span with the given configuration. | ||
|
@@ -169,13 +169,15 @@ public SpanData toSpanData() { | |
.setAttributes(getAttributes()) | ||
.setStartEpochNanos(startEpochNanos) | ||
.setEndEpochNanos(getEndEpochNanos()) | ||
.setLatencyNanos(getLatencyNanos()) | ||
.setKind(kind) | ||
.setLinks(getLinks()) | ||
.setParentSpanId(parentSpanId) | ||
.setHasRemoteParent(hasRemoteParent) | ||
.setResource(resource) | ||
.setStatus(getStatus()) | ||
.setTimedEvents(adaptTimedEvents()) | ||
.setHasEnded(hasEnded()) | ||
.build(); | ||
} | ||
|
||
|
@@ -190,6 +192,13 @@ private List<SpanData.TimedEvent> adaptTimedEvents() { | |
return result; | ||
} | ||
|
||
@Override | ||
public boolean hasEnded() { | ||
synchronized (lock) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. this proliferation of synchronization really makes me want to implement this with AtomicBoolean, since it's lock-free. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. You could remove the lock here then, but all the checks for There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. yeah. IMO, the whole thread-safety of this class is pretty janky. We should think about separating the mutable parts from the immutable and having a simpler synchronization model. |
||
return hasEnded; | ||
} | ||
} | ||
|
||
@Override | ||
public SpanContext getSpanContext() { | ||
return getContext(); | ||
|
@@ -220,14 +229,14 @@ public InstrumentationLibraryInfo getInstrumentationLibraryInfo() { | |
} | ||
|
||
/** | ||
* Returns the end nano time (see {@link System#nanoTime()}). If the current {@code Span} is not | ||
* ended then returns {@link Clock#nanoTime()}. | ||
* Returns the end nano time (see {@link System#nanoTime()}) or zero if the current {@code Span} | ||
* is not ended. | ||
* | ||
* @return the end nano time. | ||
*/ | ||
private long getEndEpochNanos() { | ||
synchronized (lock) { | ||
return getEndNanoTimeInternal(); | ||
return endEpochNanos; | ||
} | ||
} | ||
|
||
|
@@ -297,18 +306,13 @@ Map<String, AttributeValue> getAttributes() { | |
* | ||
* @return the latency of the {@code Span} in nanos. | ||
*/ | ||
long getLatencyNs() { | ||
Oberon00 marked this conversation as resolved.
Show resolved
Hide resolved
|
||
@Override | ||
public long getLatencyNanos() { | ||
synchronized (lock) { | ||
return getEndNanoTimeInternal() - startEpochNanos; | ||
return (hasEnded ? endEpochNanos : clock.now()) - startEpochNanos; | ||
} | ||
} | ||
|
||
// Use getEndNanoTimeInternal to avoid over-locking. | ||
@GuardedBy("lock") | ||
private long getEndNanoTimeInternal() { | ||
return hasBeenEnded ? endEpochNanos : clock.now(); | ||
} | ||
|
||
/** | ||
* Returns the kind of this {@code Span}. | ||
* | ||
|
@@ -363,7 +367,7 @@ public void setAttribute(String key, AttributeValue value) { | |
Preconditions.checkNotNull(key, "key"); | ||
Preconditions.checkNotNull(value, "value"); | ||
synchronized (lock) { | ||
if (hasBeenEnded) { | ||
if (hasEnded) { | ||
logger.log(Level.FINE, "Calling setAttribute() on an ended Span."); | ||
return; | ||
} | ||
|
@@ -403,7 +407,7 @@ public void addEvent(Event event, long timestamp) { | |
|
||
private void addTimedEvent(TimedEvent timedEvent) { | ||
synchronized (lock) { | ||
if (hasBeenEnded) { | ||
if (hasEnded) { | ||
logger.log(Level.FINE, "Calling addEvent() on an ended Span."); | ||
return; | ||
} | ||
|
@@ -416,7 +420,7 @@ private void addTimedEvent(TimedEvent timedEvent) { | |
public void setStatus(Status status) { | ||
Preconditions.checkNotNull(status, "status"); | ||
synchronized (lock) { | ||
if (hasBeenEnded) { | ||
if (hasEnded) { | ||
logger.log(Level.FINE, "Calling setStatus() on an ended Span."); | ||
return; | ||
} | ||
|
@@ -428,7 +432,7 @@ public void setStatus(Status status) { | |
public void updateName(String name) { | ||
Preconditions.checkNotNull(name, "name"); | ||
synchronized (lock) { | ||
if (hasBeenEnded) { | ||
if (hasEnded) { | ||
logger.log(Level.FINE, "Calling updateName() on an ended Span."); | ||
return; | ||
} | ||
|
@@ -449,12 +453,12 @@ public void end(EndSpanOptions endOptions) { | |
|
||
private void endInternal(long endEpochNanos) { | ||
synchronized (lock) { | ||
if (hasBeenEnded) { | ||
if (hasEnded) { | ||
logger.log(Level.FINE, "Calling end() on an ended Span."); | ||
return; | ||
} | ||
this.endEpochNanos = endEpochNanos; | ||
hasBeenEnded = true; | ||
hasEnded = true; | ||
} | ||
spanProcessor.onEnd(this); | ||
} | ||
|
@@ -471,7 +475,7 @@ public boolean isRecording() { | |
|
||
void addChild() { | ||
synchronized (lock) { | ||
if (hasBeenEnded) { | ||
if (hasEnded) { | ||
logger.log(Level.FINE, "Calling end() on an ended Span."); | ||
return; | ||
} | ||
|
@@ -511,7 +515,7 @@ private RecordEventsReadableSpan( | |
this.kind = kind; | ||
this.spanProcessor = spanProcessor; | ||
this.resource = resource; | ||
this.hasBeenEnded = false; | ||
this.hasEnded = false; | ||
this.numberOfChildren = 0; | ||
this.clock = clock; | ||
this.startEpochNanos = startEpochNanos; | ||
|
@@ -523,7 +527,7 @@ private RecordEventsReadableSpan( | |
@Override | ||
protected void finalize() throws Throwable { | ||
synchronized (lock) { | ||
if (!hasBeenEnded) { | ||
if (!hasEnded) { | ||
logger.log(Level.SEVERE, "Span " + name + " is GC'ed without being ended."); | ||
} | ||
} | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -17,6 +17,7 @@ | |
package io.opentelemetry.sdk.trace; | ||
|
||
import com.google.auto.value.AutoValue; | ||
import com.google.common.base.Optional; | ||
import io.opentelemetry.sdk.common.InstrumentationLibraryInfo; | ||
import io.opentelemetry.sdk.resources.Resource; | ||
import io.opentelemetry.trace.AttributeValue; | ||
|
@@ -172,6 +173,23 @@ public abstract class SpanData { | |
*/ | ||
public abstract boolean getHasRemoteParent(); | ||
|
||
/** | ||
* Returns whether this Span has already been ended. | ||
* | ||
* @return {@code true} if the span has already been ended, {@code false} if not. | ||
* @since 0.4.0 | ||
*/ | ||
public abstract boolean getHasEnded(); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I recommend just "hasEnded" without the extraneous There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Unfortunately, AutoValue seems to require a There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. yet another reason for me to hate autovalue There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I'm trying to decide if There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I like that idea! There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Being "active" (on a scope) is already another concept in OpenTelemetry, unfortunately. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I like |
||
|
||
/** | ||
* Returns the latency of the {@code Span} in nanos. If still active then returns now() - start | ||
* time. | ||
* | ||
* @return the latency of the {@code Span} in nanos. | ||
* @since 0.4.0 | ||
*/ | ||
public abstract long getLatencyNanos(); | ||
|
||
/** | ||
* An immutable implementation of {@link Link}. | ||
* | ||
|
@@ -280,6 +298,12 @@ public abstract static class Builder { | |
|
||
abstract List<io.opentelemetry.trace.Link> getLinks(); | ||
|
||
abstract Optional<Long> getStartEpochNanos(); | ||
|
||
abstract Optional<Long> getEndEpochNanos(); | ||
|
||
abstract Optional<Long> getLatencyNanos(); | ||
|
||
/** | ||
* Create a new SpanData instance from the data in this. | ||
* | ||
|
@@ -291,6 +315,14 @@ public SpanData build() { | |
setAttributes(Collections.unmodifiableMap(new HashMap<>(getAttributes()))); | ||
setTimedEvents(Collections.unmodifiableList(new ArrayList<>(getTimedEvents()))); | ||
setLinks(Collections.unmodifiableList(new ArrayList<>(getLinks()))); | ||
|
||
// Calculate latency from start & end if possible. | ||
if (!getLatencyNanos().isPresent() | ||
&& getStartEpochNanos().isPresent() | ||
&& getEndEpochNanos().isPresent() | ||
&& getEndEpochNanos().get() >= getStartEpochNanos().get()) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. this is really ugly block of code. Can we at least move it into it's own method? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Actually, this is only required for tests. The best option from my perspective would be to remove the latency from SpanData. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I am fine with removing latency from the SpanData. For the EndEpoch what is the behavior you want? |
||
setLatencyNanos(getEndEpochNanos().get() - getStartEpochNanos().get()); | ||
} | ||
return autoBuild(); | ||
} | ||
|
||
|
@@ -442,5 +474,23 @@ public abstract Builder setInstrumentationLibraryInfo( | |
* @since 0.3.0 | ||
*/ | ||
public abstract Builder setHasRemoteParent(boolean hasRemoteParent); | ||
|
||
/** | ||
* Sets to true if the span has been ended. | ||
* | ||
* @param hasEnded A boolean indicating if the span has been ended. | ||
* @return this | ||
* @since 0.4.0 | ||
*/ | ||
public abstract Builder setHasEnded(boolean hasEnded); | ||
|
||
/** | ||
* Sets to true if the span has been ended. | ||
* | ||
* @param latencyNanos A boolean indicating if the span has been ended. | ||
* @return this | ||
* @since 0.4.0 | ||
*/ | ||
public abstract Builder setLatencyNanos(long latencyNanos); | ||
} | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think it would be nice in this javadoc to define "latency" in this context, because it is a word that some may interpret as meaning "network latency", which seems like an odd thing to have on a generic Span.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Actually I think it might be better to just rename this to
currentDuration
. Latency, while technically correct (see open-telemetry/opentelemetry-specification#330), is probably confusing to most users.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Or maybe "elapsedTime" ?