[EXPORTER] Fix Elasticsearch log exporter Shutdown ignoring its timeout - #4523
[EXPORTER] Fix Elasticsearch log exporter Shutdown ignoring its timeout#4523om7057 wants to merge 2 commits into
Conversation
Shutdown() never read its timeout parameter and always returned true regardless of whether anything had actually flushed. It now flushes pending exports against the caller's deadline via ForceFlush(timeout) before cancelling sessions, and returns what that flush reported. Also closes an admission race: Export() could pass its isShutdown() check and still register a session after Shutdown() had already taken its session_counter_ snapshot in ForceFlush(), so the flush could return without ever having waited for it. Both the shutdown flag and session registration now share one lock. Fixes open-telemetry#4359
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #4523 +/- ##
==========================================
+ Coverage 83.46% 83.55% +0.09%
==========================================
Files 521 521
Lines 20412 20420 +8
==========================================
+ Hits 17034 17059 +25
+ Misses 3378 3361 -17
🚀 New features to boost your workflow:
|
…tdown-timeout # Conflicts: # CHANGELOG.md
|
Thanks for taking this one, and sorry I am five days late to it. TLDR: this is the shape I asked for in #4359, and I left something out of that issue. What I measuredSame probe, same options ( The probe is one case added to your file, with a void SendRequest(std::shared_ptr<http_client::EventHandler> handler) noexcept override
{
held_ = std::move(handler); // never answers
}Your two cases pass in 0 ms, and I think they have to. They use the fake whose session answers inside The part I got wrong in the issueI pointed at const std::chrono::steady_clock::duration wait_interval = (std::min)(
std::chrono::duration_cast<std::chrono::steady_clock::duration>(options_.timeout),
timeout_steady);The Elasticsearch one always waits the full if (std::cv_status::no_timeout != synchronization_data_->force_flush_cv.wait_for(
lk_cv, std::chrono::seconds{options_.response_timeout_}))
{
break;
}With nothing to notify it there is exactly one 30 second wait, and that break skips the line below it that subtracts the elapsed time, so Giving the Elasticsearch The other half I would not change at all. Taking Unrelated, so you do not go looking: the red One last thing, on overlap. #4337 removes |
Fixes #4359.
ElasticsearchLogRecordExporter::Shutdown()never read itstimeoutparameter and always returnedtrue, whether or not anything had actually flushed.Changes
Shutdown()now flushes pending exports against the caller's deadline viaForceFlush(timeout)before cancelling sessions, and returns what that flush reported: mirroring the patternOtlpHttpClient::Shutdown/OtlpGrpcClient::Shutdownalready use. Cancelling happens after the flush, not before, so there's still something to wait for.Export()could pass itsisShutdown()check and still register a session (bumpsession_counter_) afterShutdown()had already taken its snapshot of that counter insideForceFlush(), so the flush could return success without ever having waited for that session. Both theis_shutdown_flag and session registration now go through the sameforce_flush_mlock that already guardedForceFlush().Testing
Added two tests against the existing fake
HttpClient/Session/Request/Responsetest doubles:ShutdownReportsFlushCompletion: export completes, thenShutdown(timeout)returnstrue.ExportAfterShutdownFails:Export()afterShutdown()returnskFailure.Built and ran the exporter's test suite under both configurations (
OTELCPP_WITH_ASYNC_EXPORT_PREVIEWon and off), since the registration race only exists on the async path: both pass.