[BUG] OTLP ForceFlush can report success with requests pending, and waits on the exporter timeout rather than the caller's

otlp_grpc_client.cc と otlp_http_client.cc の ForceFlush を、既存の friend hook および func_otlp_grpc テストと併せて確認してください。両方の exporter について、in-flight request の対象範囲と caller deadline の動作を確認し、request counter にアクセスできる箇所でテストカバレッジを追加してください。ForceFlush が待機した request に対してのみ完了を報告し、指定された timeout を尊重すれば完了です。動作変更を CHANGELOG に含めてください。

Describe your environment

main at 11fa0db0, read at source level. Both paths are inside #ifdef ENABLE_ASYNC_EXPORT.

The gRPC half below is a model rather than a run of the exporter, and here is why, because it is itself worth knowing. I did build the OTLP exporters (Debian system protobuf 3.21.12 and gRPC 1.51.1) and tried to drive ForceFlush directly through the existing friend class OtlpGrpcClientTestPeer hook. That does not compile: OtlpGrpcClientAsyncData is only forward declared in otlp_grpc_client.h and defined in otlp_grpc_client.cc, so no test translation unit can dereference async_data_ even with friendship. The counters ForceFlush decides on are unreachable from a test, which is a fair part of why this function has no coverage today, and it is something a fix will have to answer for. The Elasticsearch equivalents are #4336 and #4338; this is the same family in the two exporters most people use, which is why it is a separate report.

What is the expected behavior?

ForceFlush(timeout) returns true only when the requests it was waiting for have finished, and returns within the timeout it was given.

What is the actual behavior?

OTLP gRPC returns success when any one request completes. OtlpGrpcClient::ForceFlush:

while (timeout_steady > std::chrono::steady_clock::duration::zero() &&
       request_counter > async_data_->finished_request_counter.load(std::memory_order_acquire))
{
  std::chrono::steady_clock::time_point start_timepoint = std::chrono::steady_clock::now();
  if (std::cv_status::timeout !=
      async_data_->session_waker.wait_for(lock, async_data_->export_timeout))
  {
    break;
  }
  timeout_steady -= std::chrono::steady_clock::now() - start_timepoint;
}
return timeout_steady > std::chrono::steady_clock::duration::zero();

std::cv_status::timeout != status is true when the wait was notified, so any notification leaves the loop without re-checking the counter, and the return is the leftover duration rather than the predicate.

A model that keeps the loop and both branch conditions exactly, with two requests where one completes:

started=2 finished=1 ForceFlush returned true after 50 ms

That is a model, not the exporter. What I can state about the exporter itself is structural: the counter is only re-read by the while condition, and the break skips it.

The comment above that break refers to running_sessions_ and to cleaning up gc sessions, neither of which exists in otlp_grpc_client.cc. Both are OtlpHttpClient members, and the comment is a verbatim copy of the one in otlp_http_client.cc, down to the missing space in forever.We. The HTTP original reads:

if (std::cv_status::timeout == session_waker_.wait_for(lock, options_.timeout))
{
  cleanupGCSessions();
}
else if (finished_session_counter_.load(std::memory_order_acquire) >= wait_counter)
{
  break;
}

so it breaks on a notification only if the counter predicate also holds. The gRPC copy dropped that else if and kept a bare break. The break is not guarding the lost-wakeup window the comment describes; the bounded wait_for is.

Both wait on the exporter's timeout rather than the caller's remaining time. gRPC waits async_data_->export_timeout, HTTP waits options_.timeout. A ForceFlush(1ms) can therefore block far longer than asked. The HTTP loop does subtract the elapsed time on every path, so unlike gRPC it terminates and returns false correctly; its problem is the overrun, not a false success. OtlpHttpClient::Shutdown calls ForceFlush(std::chrono::milliseconds{1}) in a loop, and each call can currently take up to options_.timeout.

The spec is explicit that a processor MUST prioritize honoring the timeout over finishing all calls, and that an exporter's Export MUST NOT block indefinitely.

Additional context

Two design questions I would rather settle with you before writing code, since they change the shape of the fix.

Should ForceFlush wait only for what was in flight when it was entered? Both implementations snapshot a counter at entry, so that is the current intent, and it is what keeps an indefinite flush from being starved by a steady stream of new exports. Confirming it would be useful, because the HTTP loop also breaks on running_sessions_.empty(), which is the other reading.

Can the gRPC completion path take session_waker_lock? The counters are incremented and notify_all() called without it, so a completion landing between the waiter's predicate check and its park is missed. For gRPC that looks safe to fix directly, since running_calls_lock is released before that point. For HTTP it is not: ReleaseSession notifies while holding session_manager_lock_, and ForceFlush takes session_waker_lock_ and then session_manager_lock_, so making the notifier also take session_waker_lock_ inverts the order. HTTP would need a bounded re-check interval clamped to the caller's deadline instead of one sleep to it. That asymmetry is a real constraint rather than a style preference, and it is the main reason I would send these as two PRs rather than one.

On blast radius: no existing test asserts the return value of ForceFlush for either exporter, so nothing should flip. The exposure is wall clock timing, and the user visible change is that callers who get true today while exports are pending will start getting false. That is the point of the fix, but it is a behaviour change in the two most used exporters and belongs in the CHANGELOG.

One thing to know when reading CI on any PR that touches this: func_otlp_grpc has a pre-existing nondeterministic double free that aborts after the tests report passing, and it reds gcc-14 and clang-18 on main as well. It is not related.

I am happy to do both fixes once you have a view on the two questions.