[BUG] Report an Elasticsearch async export's outcome exactly once - #4502
Draft
thc1006 wants to merge 2 commits into
Draft
[BUG] Report an Elasticsearch async export's outcome exactly once#4502thc1006 wants to merge 2 commits into
thc1006 wants to merge 2 commits into
Conversation
thc1006
force-pushed
the
fix/es-exactly-once-4338
branch
from
August 31, 2026 15:13
fc104af to
779767c
Compare
thc1006
added a commit
to thc1006/opentelemetry-cpp
that referenced
this pull request
Sep 1, 2026
…on identity ForceFlush waited for options_.response_timeout_ rather than the caller's timeout, and the timeout branch returned true whatever had happened, so every flush that ran out of time reported success. It also compared monotonic totals with no session identity, so a completion from a session started after the call could satisfy a waiter for one started before it, and a batch already inside Export() was not waited for at all. One steady_clock deadline taken at entry, and a wait on a predicate over the set of running session ids against a watermark. wait_until returns the predicate, so the answer is the caller's question rather than a leftover duration. The serialising lock is gone: each call snapshots what it waits for and publishes nothing, so two callers were already safe side by side. Stacked on open-telemetry#4502, which carries the exactly-once completion this accounting depends on. That half was extracted so each pull request closes one issue and is reviewable on its own. Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
3 tasks
thc1006
force-pushed
the
fix/es-exactly-once-4338
branch
from
September 1, 2026 12:14
779767c to
e2d4113
Compare
thc1006
added a commit
to thc1006/opentelemetry-cpp
that referenced
this pull request
Sep 1, 2026
…on identity ForceFlush waited for options_.response_timeout_ rather than the caller's timeout, and the timeout branch returned true whatever had happened, so every flush that ran out of time reported success. It also compared monotonic totals with no session identity, so a completion from a session started after the call could satisfy a waiter for one started before it, and a batch already inside Export() was not waited for at all. One steady_clock deadline taken at entry, and a wait on a predicate over the set of running session ids against a watermark. wait_until returns the predicate, so the answer is the caller's question rather than a leftover duration. The serialising lock is gone: each call snapshots what it waits for and publishes nothing, so two callers were already safe side by side. Stacked on open-telemetry#4502, which carries the exactly-once completion this accounting depends on. That half was extracted so each pull request closes one issue and is reviewable on its own. Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #4502 +/- ##
==========================================
+ Coverage 83.47% 83.73% +0.26%
==========================================
Files 522 522
Lines 20440 20453 +13
==========================================
+ Hits 17061 17124 +63
+ Misses 3379 3329 -50
🚀 New features to boost your workflow:
|
thc1006
force-pushed
the
fix/es-exactly-once-4338
branch
from
September 1, 2026 13:14
e2d4113 to
f9817df
Compare
thc1006
added a commit
to thc1006/opentelemetry-cpp
that referenced
this pull request
Sep 1, 2026
…on identity ForceFlush waited for options_.response_timeout_ rather than the caller's timeout, and the timeout branch returned true whatever had happened, so every flush that ran out of time reported success. It also compared monotonic totals with no session identity, so a completion from a session started after the call could satisfy a waiter for one started before it, and a batch already inside Export() was not waited for at all. One steady_clock deadline taken at entry, and a wait on a predicate over the set of running session ids against a watermark. wait_until returns the predicate, so the answer is the caller's question rather than a leftover duration. The serialising lock is gone: each call snapshots what it waits for and publishes nothing, so two callers were already safe side by side. Stacked on open-telemetry#4502, which carries the exactly-once completion this accounting depends on. That half was extracted so each pull request closes one issue and is reviewable on its own. Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
AsyncResponseHandler called the result callback directly from OnResponse and from each terminal OnEvent state with no guard, and ReadError, WriteError and Destroyed fell through a default label and called nothing. The HTTP client can deliver both a response and a terminal event for one request, so one export could report twice, and it can end on one of those three states and report nothing at all. The exporter counts one finished session per export. Reporting twice overshoots that count for the life of the exporter. Reporting never leaves a flush waiting on a session that has already ended. Every path goes through one CompleteOnce now, a compare exchange that reports at most once and keeps the first verdict. The switch lists every state with no default, so a state added upstream fails to compile rather than going uncounted, and the destructor reports a failure for a handler torn down without an outcome. The completion line said trace span(s) in the log exporter and says log record(s) now. The cases read that line to count outcomes, and the wording was wrong either way. Nine cases drive a fake HTTP client through the public constructor: each terminal ordering a real session can produce, a response and a teardown event in both orders, and the concurrent version of each. Removing the compare exchange turns six of the nine red. Extracted from open-telemetry#4337, which is 1526 lines and closes two issues. What stays there is the ForceFlush deadline and watermark accounting for open-telemetry#4336, including four completion cases that verify this guard through the flush rather than through the log line. Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
Main's open-telemetry#4071 and open-telemetry#4501 put FakeResponse, FakeRequest, FakeSession and FakeHttpClient in an unnamed namespace at the top of this file, and this branch already had four of those names in a second unnamed namespace lower down. Reopening an unnamed namespace names the same namespace, so the rebase merged both with no conflict at all and left four redefinitions. One set now. The session and the client take a script and default to answering the way main's did, so main's own call site needs no edit. The script carries the handler as a shared_ptr rather than a reference, because the cases here have to keep it and send a second event to it, and the client keeps its on_create_session and on_cancel_all hooks, both empty by default. The default body stays as main wrote it. This branch does not change how the exporter decides success, so what main's cases send still passes here. Verified in both configurations with maintainer mode on: 12 cases, 12 passing with async export and 3 passing with 9 skipping without it. Removing CompleteOnce's compare and exchange turns six of them red, so the rewritten fixtures still discriminate. Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
thc1006
force-pushed
the
fix/es-exactly-once-4338
branch
from
September 8, 2026 06:48
f9817df to
9d5224c
Compare
thc1006
added a commit
to thc1006/opentelemetry-cpp
that referenced
this pull request
Sep 8, 2026
…on identity ForceFlush waited for options_.response_timeout_ rather than the caller's timeout, and the timeout branch returned true whatever had happened, so every flush that ran out of time reported success. It also compared monotonic totals with no session identity, so a completion from a session started after the call could satisfy a waiter for one started before it, and a batch already inside Export() was not waited for at all. One steady_clock deadline taken at entry, and a wait on a predicate over the set of running session ids against a watermark. wait_until returns the predicate, so the answer is the caller's question rather than a leftover duration. The serialising lock is gone: each call snapshots what it waits for and publishes nothing, so two callers were already safe side by side. Stacked on open-telemetry#4502, which carries the exactly-once completion this accounting depends on. That half was extracted so each pull request closes one issue and is reviewable on its own. Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes #4338.
AsyncResponseHandlercalls the exporter's result callback directly fromOnResponseand from each terminalOnEventstate with no guard, andReadError,WriteErrorandDestroyedfall through adefaultlabel and call nothing.The HTTP client can deliver both a response and a terminal event for one request, so one export can report twice. It can also end on one of those three states and report nothing at all. The exporter counts one finished session per export, so the first overshoots that count for the life of the exporter, and the second leaves a flush waiting on a session that has already ended.
Every path goes through one
CompleteOncenow, a compare exchange that reports at most once and keeps the first verdict. The switch lists every state with nodefault, so a state added upstream fails to compile rather than going uncounted, and the destructor reports a failure for a handler torn down without an outcome.One thing comes with it that is not strictly the fix. The completion line said
trace span(s)in the log exporter; it sayslog record(s)now. The cases below read that line to count outcomes, and the wording was wrong either way.Nine cases in
es_log_record_exporter_test.cc, driven by a fake HTTP client through the public constructor: each terminal ordering a real session can produce, a response and a teardown event in both orders, and the concurrent version of each. Removing the compare exchange turns six of the nine red.Extracted from #4337, which is 1526 lines and closes two issues. What stays there is the
ForceFlushdeadline and watermark accounting for #4336, including four completion cases that verify this guard through the flush rather than through the log line, which need that accounting to work.For significant contributions please make sure you have completed the following items:
CHANGELOG.mdupdated for non-trivial changes