-
Notifications
You must be signed in to change notification settings - Fork 829
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
Only drop elements exported by BatchSpanProcessor #1567
Conversation
This commit takes an approach where only the actual elements passed onto an exporter are removed from the internal buffer of spans within a BatchSpanProcessor. Any pressure on the buffer becoming full will result in the BatchSpanProcessor dropping elements as per its original design. Prior to this commit, spans could be dropped by the BatchSpanProcessor without being reported.
sdk/tracing/src/main/java/io/opentelemetry/sdk/trace/export/BatchSpanProcessor.java
Outdated
Show resolved
Hide resolved
sdk/tracing/src/main/java/io/opentelemetry/sdk/trace/export/BatchSpanProcessor.java
Outdated
Show resolved
Hide resolved
} else { | ||
logger.log(Level.FINE, "Exporter busy. Dropping spans."); | ||
return 0; |
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.
Returning zero is key - this is what'll cause the internal buffer to mount up and for the existing span-drop functionality of logging to kick in.
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.
Because of
sdk/tracing/src/main/java/io/opentelemetry/sdk/trace/export/BatchSpanProcessor.java
Show resolved
Hide resolved
} | ||
// Execute the batch export outside the synchronized to not block all producers. | ||
exportBatches(spansCopy); | ||
int taken = onBatchExport(spansCopy); |
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 might be missing it, but I think this will cause multiple batches to be sent concurrently? If so, I think it's not respecting the spirit of maxExportBatchSize
. To be honest, I don't know exactly what the spirit of maxExportBatchSize
is but I think it's one of 1) send batches sequentially or 2) wait scheduledDelayMillis
between each chunk of maxExportBatchSize
no matter what. #1565 aims for 1), neither of our PRs aim for 2) :( But I guess if we're sending concurrently that's not good for BSP, that's the SSP's role. Let me know if I'm confused though.
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.
It isn’t sending an export concurrently. Only one export is permitted at a time within the onExportBatch function.
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.
Exporting “no matter what” on schedule is what things look like before this PR. ;-)
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.
Ah I see how the return 0 works. Isn't this effectively a spinlock because we'll keep on looping, find the queue is larger than batch size, try to export, find it's not available, and continue until it's available again? I wouldn't expect to see spinning to wait for I/O, is it better than parking?
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.
Good point. It would indeed spin until the number of buffer elements drops below the max buffer size. I think we should move the condition on the wait also... that way it wouldn't spin. The batch would then just wake up on its timer no matter what and then try another export. This would ultimately represent the park that you suggested.
I will push another commit now along with some other small changes to improve comprehension.
Because of #1567 (comment) my current recommendation is to merge #1565 since we do need a quick fix for BSP dropping spans that shouldn't be and it seems the simplest. All of the related PRs have made me believe we need to prioritize #1560 #729 before doing a deep dive here |
I see this PR as being much simpler than 1565. The BSP’s contract acknowledges that spans can be dropped, so we’ve not violated that contract. Let’s get this right rather than look for a quick fix. |
Renamed the onBatchExport to tryExport as this more correctly conveys intent. Also introduced a dropSpans function that should be more performant over what I had.
We should avoid spinning if the buffer is not full. The change here keeps things simple where the batch processor only wakes up on its schedule, tries to export, retains elements that it can't export, and then sleeps again.
@@ -177,7 +177,7 @@ public void forceFlush() { | |||
private final AtomicBoolean exportAvailable = new AtomicBoolean(true); | |||
|
|||
@GuardedBy("monitor") | |||
private final List<ReadableSpan> spansList; | |||
private final ArrayList<ReadableSpan> spansList; |
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.
Exposing an array list here as the operations we perform on it assumes an array in terms of bulk copying and therefore, o(1) element access.
Just realised that the worker thread can now be eliminated
sdk/tracing/src/main/java/io/opentelemetry/sdk/trace/export/BatchSpanProcessor.java
Outdated
Show resolved
Hide resolved
// In the case of a spurious wakeup we export only if we have at least one span in | ||
// the batch. It is acceptable because batching is a best effort mechanism here. | ||
try { | ||
monitor.wait(scheduleDelayMillis); |
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 this causes the wait to happen between each export batch, rather than between each "processing of the queue". It effectively means the queue size parameter is not having much effect if I'm not mistaken.
FWIW, I am interested in flushing in an async manner :) I think the way to do it is to have a separate Flusher. What I'm expecting is for it to look like something like
ExecutorService executor;
init() executor.schedule(wakeup);
wakeup {
if (spans.empty)
executor.schedule(wakeup)
drained = spans.drain
new Flusher(drained).flush();
Flusher {
pending
Flusher(spans) pending = spans
flush() {
if (pending.isEmpty()) {
executor.schedule(wakeup)
return
}
taken = pending.take(batchSize)
result = exporter.export(taken)
result.whenComplete(this::flush)
}
I think this has the properties that we want - run through entire queue when exporting, export a batch at a time, and delay between each queue processing (not between every batch as in the right side here, nor potentially no delay ever like left side here). And consecutive flushes without blocking.
So my plan is #1565, then #729, then add AsyncFlusher. @jkwatson has wanted us to migrate to an ExecutorService
for a long time and I agree :) I think it will make our lives simpler when actually addressing the asyncronous export. Does this plan make sense?
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.
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.
So, if I've got this right... you're making a distinction here between the time interval in terms of processing the queue vs the time interval between exporting to an exporter. You're also favouring the former.
You want to see exporting happen continually if there are more elements in the queue.
Correct?
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.
Yeah - at least that's my understanding of the spec / goal of the class, but I could be wrong in my reading of course :)
A second reading makes me think actually this PR may have the right semantics since it says scheduledDelayMillis = delay between export, and maxExportBatchSize = maximum size of an export. I'm having trouble invisioning how I would actually set maxExportBatchSize different from queueSize but this PR seems ok to me too now. Interested in hearing what others think the BSP is "supposed to do" though :)
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.
OK, I've just pushed another commit.
The worker thread has been removed and we now instead use the timer for scheduling work, thus saving us a thread. In addition, if there remains work to be done once the export has completed then we queue it for running immediately.
A test has changed slightly in that it was previously relying on the worker thread becoming blocked; which it now no longer does.
The worker thread has been removed and we now instead use the timer for scheduling work, thus saving us a thread. In addition, if there remains work to be done once the export has completed then we queue it for running immediately. A test has changed slightly in that it was previously relying on the worker thread becoming blocked; which it now no longer does.
System.arraycopy(spansList.toArray(), count, retainedSpanList, 0, remaining); | ||
spansList.clear(); | ||
spansList.addAll(Arrays.asList(retainedSpanList)); | ||
} |
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.
There has to be a better way of dropping elements from an array... Given that clear
traverses the array and nulls elements, we've effectively got three traverses of the array. Now in practical terms, retainedSpanList
should be empty most times, or at least only a few elements. So the array copying at L308 and L310 is going to be negligible.
if (!spansList.isEmpty()) { | ||
timer.schedule(new WorkerTask(), 0); | ||
} | ||
} |
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.
We now steal more work if there's some more available.
|
Adjusted the stress test as it can only guarantee that the buffer size is sent to the exporter now. I'm noticing that several thousand get exported, but some do (and should) get lost. Also, the test did highlight one area of neglect where I should be waking up the timer when the buffer is half full and there's no export in progress.
stressTestBuilder.build().run(); | ||
assertThat(countingSpanExporter.numberOfSpansExported.get()).isEqualTo(8_000); | ||
assertThat(countingSpanExporter.numberOfSpansExported.get()) | ||
.isGreaterThanOrEqualTo(defaultMaxQueueSize); |
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.
This needed to change given that we are now fully async. We can't guarantee that all spans get through. This is ok though as it is in line with the BatchSpanProcessor
's contract.
In reality, this test does see several thousand get through.
Codecov Report
@@ Coverage Diff @@
## master #1567 +/- ##
============================================
+ Coverage 91.49% 91.61% +0.11%
Complexity 976 976
============================================
Files 116 116
Lines 3517 3518 +1
Branches 304 303 -1
============================================
+ Hits 3218 3223 +5
+ Misses 206 203 -3
+ Partials 93 92 -1
Continue to review full report at Codecov.
|
Let's not overwhelm the exporter...
…uffer This class should now behave fully in accordance with the spec
@huntc Chatted with @jkwatson today about this and we decided that because the current behavior is only in snapshot, not released, we don't have to rush a fix in. So going to close my #1565 :-) He also think we really should go ahead and clean up the processor before (or perhaps while) fixing it rather than continuing work with the current monitor / worker pattern. I'm working on a PR for that. @huntc does that sound OK to you? I'm keeping this PR in mind instead of adding any blocking - I think the code will be dramatically simplified and hope it helps us with future possible improvements. |
Closing given the work of #1571 |
This PR takes an approach where only the actual elements passed onto an exporter is removed from the internal buffer of spans within a
BatchSpanProcessor
. Any pressure on the buffer becoming full will result in theBatchSpanProcessor
dropping elements as per its original design.Prior to this PR, spans could be dropped by the
BatchSpanProcessor
without being reported.Along the way, it occurred to me that the worker thread can be replaced by using the timer thread that we have to have. I've now affected code changes there too, which I think simplifies the
BatchSpanProcessor
.Fixes #1566
cc @anuraaga