Skip to content

[EXPORTER] Fix Elasticsearch log exporter Shutdown ignoring its timeout - #4523

Open
om7057 wants to merge 2 commits into
open-telemetry:mainfrom
om7057:fix/elasticsearch-shutdown-timeout
Open

[EXPORTER] Fix Elasticsearch log exporter Shutdown ignoring its timeout#4523
om7057 wants to merge 2 commits into
open-telemetry:mainfrom
om7057:fix/elasticsearch-shutdown-timeout

Conversation

@om7057

@om7057 om7057 commented Sep 3, 2026

Copy link
Copy Markdown
Contributor

Fixes #4359.

ElasticsearchLogRecordExporter::Shutdown() never read its timeout parameter and always returned true, whether or not anything had actually flushed.

Changes

  • Shutdown() now flushes pending exports against the caller's deadline via ForceFlush(timeout) before cancelling sessions, and returns what that flush reported: mirroring the pattern OtlpHttpClient::Shutdown / OtlpGrpcClient::Shutdown already use. Cancelling happens after the flush, not before, so there's still something to wait for.
  • Closes the admission race the issue also flagged: Export() could pass its isShutdown() check and still register a session (bump session_counter_) after Shutdown() had already taken its snapshot of that counter inside ForceFlush(), so the flush could return success without ever having waited for that session. Both the is_shutdown_ flag and session registration now go through the same force_flush_m lock that already guarded ForceFlush().

Testing

Added two tests against the existing fake HttpClient/Session/Request/Response test doubles:

  • ShutdownReportsFlushCompletion: export completes, then Shutdown(timeout) returns true.
  • ExportAfterShutdownFails:Export() after Shutdown() returns kFailure.

Built and ran the exporter's test suite under both configurations (OTELCPP_WITH_ASYNC_EXPORT_PREVIEW on and off), since the registration race only exists on the async path: both pass.

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
@om7057
om7057 requested a review from a team as a code owner September 3, 2026 03:03
@codecov

codecov Bot commented Sep 3, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 83.33333% with 2 lines in your changes missing coverage. Please review.
✅ Project coverage is 83.55%. Comparing base (eec1b36) to head (6b26351).

Files with missing lines Patch % Lines
...orters/elasticsearch/src/es_log_record_exporter.cc 83.34% 2 Missing ⚠️
Additional details and impacted files

Impacted file tree graph

@@            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     
Files with missing lines Coverage Δ
...y/exporters/elasticsearch/es_log_record_exporter.h 100.00% <ø> (ø)
...orters/elasticsearch/src/es_log_record_exporter.cc 62.86% <83.34%> (+15.13%) ⬆️
🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@thc1006

thc1006 commented Sep 8, 2026

Copy link
Copy Markdown
Member

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. ForceFlush on this exporter does not bound its wait by the caller's budget the way the OTLP one does, so Shutdown(1us) now blocks for response_timeout_, 30 seconds by default, and still returns true. Numbers below. One clamp in ForceFlush closes it, and nothing here is waiting on anything of mine.

What I measured

Same probe, same options (WITH_ELASTICSEARCH=ON, WITH_ASYNC_EXPORT_PREVIEW=ON), same machine:

main    312acb69   Shutdown(1us) returned true after 0 ms
#4523   6b26351b   Shutdown(1us) returned true after 30000 ms

The probe is one case added to your file, with a Session that keeps the handler and never answers, so there is still an export outstanding when Shutdown runs:

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 SendRequest, which your own comment says, so there is never anything pending by the time Shutdown is called, and that is the one situation the new return value is there to describe.

The part I got wrong in the issue

I pointed at OtlpHttpClient::Shutdown as the model and did not say that the two ForceFlush implementations differ where it matters. The OTLP one clamps each wait to what the caller has left:

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 response_timeout_:

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 timeout_steady is still positive and the function returns true. That behaviour is #4336 and it predates your PR by a long way. What makes it visible here is that Shutdown on main never called ForceFlush at all, so the 0 ms above is not a bug your PR fixes, it is a wait that did not exist before it.

Giving the Elasticsearch ForceFlush the same clamp would make Shutdown(timeout) mean what your doc comment says. It is small and it belongs to the behaviour this PR is already about. A case with something still outstanding would keep it honest, and the probe above is yours to lift if it helps.

The other half I would not change at all. Taking force_flush_m around both the isShutdown() check and the registration is the right fix for the admission race, and your comment explaining why is clearer than what I wrote in the issue.

Unrelated, so you do not go looking: the red CMake msvc (maintainer mode) with C++20 is not yours, vcpkg got HTTP 504 fetching zlib v1.3.1.tar.gz.

One last thing, on overlap. #4337 removes force_flush_m and rewrites ForceFlush, so whichever of us lands second has real work to do. Please do not hold this for that. I will rebase mine onto yours. Between #4501, this and #4530 you have been working through this exporter faster than I have been reviewing it, and I would rather take the merge cost than slow that down.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[BUG] Elasticsearch exporter Shutdown ignores its timeout and always reports success

2 participants