[BUG] BatchSpanProcessor::Shutdown ignores its timeout when the worker thread is blocked in Export()

[brhenc]

Body

Describe your environment

Reproduced on main at 11fa0db0 (also present in the latest release, v1.28.0 -- this is not a regression). Linux, built via the project's own CMake build (USE_HTTP_CLIENT_CURL, OTLP HTTP exporter enabled). Confirmed by reading sdk/src/trace/batch_span_processor.cc and by timing a standalone reproduction program against the built SDK.

Steps to reproduce

BatchSpanProcessor::InternalShutdown(timeout) joins the worker thread unconditionally, before it ever looks at timeout:

bool BatchSpanProcessor::InternalShutdown(std::chrono::microseconds timeout) noexcept
{
  auto start_time = std::chrono::system_clock::now();
  std::lock_guard<std::mutex> shutdown_guard{synchronization_data_->shutdown_m};
  bool already_shutdown = synchronization_data_->is_shutdown.exchange(true);

  if (worker_thread_.joinable())
  {
    {
      std::lock_guard<std::mutex> cv_lock(synchronization_data_->cv_m);
      synchronization_data_->is_force_wakeup_background_worker.store(true, std::memory_order_release);
      synchronization_data_->cv.notify_all();
    }
    worker_thread_.join();          // <-- unconditional, untimed
  }

  GetWaitAdjustedTime(timeout, start_time);   // <-- `timeout` is only consulted after the join returns
  if (!already_shutdown && exporter_ != nullptr)
  {
    return exporter_->Shutdown(timeout);
  }
  return true;
}

notify_all() only wakes the worker if it is currently parked in DoBackgroundWork()'s cv.wait_for(). If the worker is instead inside Export() -> exporter_->Export(...), blocked on a live network call to an unresponsive collector, the notification does nothing: the thread is busy, not waiting. worker_thread_.join() then blocks for however long that Export() call takes to fail.

DrainQueue(), called by the worker right before it exits, has the same problem -- it loops calling Export() for every remaining buffered batch with no deadline of its own:

void BatchSpanProcessor::DrainQueue()
{
  while (true)
  {
    if (buffer_.empty() && ...) break;
    Export();
  }
}

Minimal repro:

1. Start a real TCP listener that accepts a connection and never responds (a "blackhole" collector).
2. Point an OtlpHttpExporter at it (default options, so a 10s request timeout).
3. Wrap it in a BatchSpanProcessor with a short schedule_delay_millis (e.g. 100ms).
4. Feed the processor one span (OnStart/OnEnd), then sleep ~300ms so the periodic export is genuinely in flight against the blackhole.
5. Call processor->Shutdown(std::chrono::microseconds(1)) and time it.

Happy to attach the full standalone program to the issue or a follow-up PR.

What is the expected behavior?

Shutdown(timeout) should return at or close to the requested timeout (here, ~1 microsecond), regardless of what the worker thread happens to be doing at the time.

What is the actual behavior?

Calling Shutdown(1 microsecond) now...
Shutdown() returned: true
Actual wall-clock time to return: 9702 ms

The 9702ms is entirely the OTLP HTTP exporter's own default 10s request timeout running its course -- the caller's timeout had no effect on it. Separately, Shutdown() returns true even though the export it was waiting on failed, so the return value doesn't reflect what happened either (same shape of gap as #4359 for the Elasticsearch exporter's Shutdown).

Additional context

Not exporter-specific: BatchSpanProcessor and BatchLogRecordProcessor (which share this structure) sit in front of every batching exporter -- OTLP HTTP, OTLP gRPC, Elasticsearch, etc. -- so any host application using batch export and expecting a bounded shutdown (graceful termination on SIGTERM, zero-downtime reload, etc.) is exposed regardless of which exporter is configured.

Distinct from #4359 (Elasticsearch exporter's own Shutdown ignores its timeout) and #4339 (OTLP gRPC ForceFlush returns on the first notification rather than checking its predicate) -- both of those are exporter-level. This one is in the processor layer that sits in front of every batching exporter, and is a different code path (the worker-thread join, not the exporter's own shutdown/flush logic).

The fix direction isn't entirely obvious, which is why I'm filing before attempting a patch: the straightforward-looking approach -- wait up to timeout for a completion signal from the worker, and stop waiting if it doesn't finish in time -- runs into worker_thread_ being a raw std::thread bound to this via &BatchSpanProcessor::DoBackgroundWork. If Shutdown()/~BatchSpanProcessor() gives up on the join before the worker actually exits, avoiding std::thread's destructor calling std::terminate() on a still-joinable thread means detach()-ing it -- but a detached thread still touching this->buffer_ / this->exporter_ after the processor object is destroyed is a new use-after-free, not a fix. A safe version likely needs the worker's state (buffer, exporter, synchronization data) to be reachable independent of the BatchSpanProcessor object's own lifetime, so a timed-out Shutdown() can return without the abandoned thread touching freed memory once it eventually does finish. That's a bigger structural change than the fix itself, so I'd rather confirm the shape a maintainer wants before sending a patch than guess.

[brhenc]

This issue was found by a SAST scan and traced to affect for example NGINX: open-telemetry/opentelemetry-cpp-contrib#685
I'm working through the SAST scan report backlog. Might take me some time to get to creating a PR for this.

[mateenali66]

This is against post-#4382 code, so the notify half is already fixed for trace and what is left is the untimed join. Probably worth keeping it separate from the lost-wakeup cluster (#4382 for trace, #4400 and #4518 for logs, #4365 for metrics), since those are all about the notify reaching a parked worker and this is the case where the notify is irrelevant.

It also does not look trace-only. BatchLogRecordProcessor::InternalShutdown has the identical join() after notify_all(), and there the store and the notify are still not under cv_m, so that one has both halves. PeriodicExportingMetricReader::OnShutDown guards with joinable() but its join is untimed as well.

#4518 is open on the logs file right now. Is it worth scoping this across all three processors so the two changes do not collide?

Suggest triage/accepted.

[yigitcan-ozturk]

I’d like to take this on if there’s no conflict with your planned work. I’d keep the scope focused on the unbounded join() / worker-lifetime problem rather than the already-addressed lost-wakeup path.

My plan is to first reproduce the timeout violation with a blocking exporter, then isolate the worker-owned state needed after Shutdown(timeout) returns so we can avoid both an unbounded join and any detached-thread use-after-free. I’ll also check the equivalent BatchLogRecordProcessor path so the trace/log behavior stays consistent, while avoiding overlap with #4518’s notification changes.

If that scope works for you, I’ll proceed with a focused PR and regression coverage around bounded shutdown semantics.

[brhenc]

@yigitcan-ozturk if you are asking me - please feel free. I'm more of a C guy and I primarily get to interact with the async API (although there is some shared effect on the async API too). The lead on haproxy-opentelemetry has clamped down the default timeouts on the exporters which resolves the concern I had downstream. A HAProxy filter may not block for more than 1 second or the watchdog triggers (process crash). So the timeouts are stricter than in the worker models other server software uses.

There were other issues but the flurry of activity since I started the SAST review (August 3-5) already fixed a issue I planned to address. So I have to say the project is doing awesome which allays some of the concerns I had.

Patches may impact NGINX and Apache2 in some way which seem to be the two downstream users of the API that need to be tested.