Skip to content

BatchLogProcessor::emit: current_batch_size underflows (decrement before increment) -> 'attempt to add with overflow' panic / accounting corruption under load #3573

Description

@simon-1M

What happened

BatchLogProcessor::emit panicked with attempt to add with overflow under sustained high-volume, multi-threaded logging:

panicked at .../opentelemetry_sdk-0.31.0/src/logs/batch_log_processor.rs:164:20:
attempt to add with overflow

The panic unwinds on whatever application thread emitted the log (via the opentelemetry-appender-tracing bridge, emit runs inline on the caller's thread), so it can take down unrelated application tasks.

Root cause: decrement can occur before increment → current_batch_size underflows → + 1 overflows

In emit, the record is sent to the channel before the counter is incremented:

fn emit(&self, record: &mut SdkLogRecord, instrumentation: &InstrumentationScope) {
    let result = self.logs_sender.try_send(Box::new((record.clone(), instrumentation.clone())));   // (1) SEND
    match result {
        Ok(_) => {
            if self.current_batch_size.fetch_add(1, Ordering::AcqRel) + 1   // (2) INCREMENT, then `+ 1`
                >= self.max_export_batch_size
            { ... }

The worker thread drains records and decrements:

current_batch_size.fetch_sub(count_of_logs, Ordering::AcqRel);

Because the record is enqueued at (1) before the producer increments at (2), the worker can dequeue that record and fetch_sub for it before the producer's fetch_add runs. Under high concurrency this lets the decrements outrun the increments and drives the AtomicUsize negative, i.e. it wraps to near usize::MAX. On the next emit, fetch_add(1) returns that near-usize::MAX value and the non-atomic + 1 overflows.

Impact

  • With overflow-checks = true (common in correctness-sensitive builds — e.g. blockchain / financial software): the + 1 is a hard panic, which crashes the emitting thread/task. In our case it brought down a node.
  • With the default release profile (overflow-checks = false): the + 1 silently wraps current_batch_size back to a small value, corrupting batch-size accounting (spurious or skipped export triggers). So this is a latent correctness bug for everyone, and a crash for overflow-checks builds.

Versions

Confirmed the unguarded accounting is present in 0.31.0, and still present in 0.32.0 / 0.32.1 (latest release) and main — between 0.31 and 0.32 only the memory ordering changed (RelaxedAcqRel), which does not change the arithmetic. No checked_add/saturating_* is used. The 0.31.0 changelog's "batch size accounting in BatchSpanProcessor when queue is full (#3089)" fix was for the span processor, not the log processor.

Reproduction

Observed in a real deployment under ~1448 logs/s of concurrent, multi-threaded, trace-level logging that saturated the export channel. We do not yet have a minimal standalone reproducer, but the ordering bug (send-before-increment vs. worker decrement) is clear by inspection and the panic location is unambiguous.

Suggested fix

  • Increment current_batch_size before try_send (and decrement back on a try_send error), so the counter is never decremented for a record that has not yet been counted; and/or
  • Use saturating_add / saturating_sub (or restructure the accounting) so the counter can never wrap, regardless of interleaving.

Related (different symptom — stack overflow rather than integer overflow): #2897, #3161.

Metadata

Metadata

Assignees

No one assigned

    Labels

    A-logArea: Issues related to logsM-sdkbugSomething isn't workingtriage:acceptedHas been triaged and accepted.

    Type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions