Skip to content

SimpleLogRecordProcessor/SimpleSpanProcessor.forceFlush() result never completes when an export completes while ofAll() counts the pending set #8995

Open

Description

@Jozef7467

Describe the bug

SimpleLogRecordProcessor.forceFlush() (and SimpleSpanProcessor.forceFlush(), same code) returns CompletableResultCode.ofAll(pendingExports), passing the live ConcurrentHashMap-backed set from which the whenComplete callback registered in onEmit removes each export once it completes. ofAll reads codes.size() and then iterates the collection. An export that completes between those two steps is removed before the (weakly consistent) iterator reaches it, so it is counted in pending but never counted down. The returned result then never completes, although nothing is pending any more. A caller doing forceFlush().join(timeout, unit) waits for the whole timeout; a caller joining without a timeout waits forever.

The code is identical in 1.49.0, 1.65.0, 1.67.0 and on main today. #8773 (1.66.0) changed how completion actions run but did not touch ofAll or either forceFlush().

Steps to reproduce

SDK only; the exporter hands back result codes that are completed on other threads, as a real asynchronous exporter does:

import io.opentelemetry.api.logs.Logger;
import io.opentelemetry.sdk.common.CompletableResultCode;
import io.opentelemetry.sdk.logs.SdkLoggerProvider;
import io.opentelemetry.sdk.logs.data.LogRecordData;
import io.opentelemetry.sdk.logs.export.LogRecordExporter;
import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor;

import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
import java.util.List;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;

/** SimpleLogRecordProcessor.forceFlush() may never complete when an export completes while ofAll() counts the pending set. */
public class ForceFlushRace {
  public static void main(String[] args) throws Exception {
    int rounds = args.length > 0 ? Integer.parseInt(args[0]) : 2000;
    int exportsPerRound = args.length > 1 ? Integer.parseInt(args[1]) : 5;
    List<CompletableResultCode> exports = Collections.synchronizedList(new ArrayList<>());
    LogRecordExporter exporter = new LogRecordExporter() {
      @Override public CompletableResultCode export(Collection<LogRecordData> logs) {
        CompletableResultCode result = new CompletableResultCode(); // completed later, on another thread
        exports.add(result);
        return result;
      }
      @Override public CompletableResultCode flush() { return CompletableResultCode.ofSuccess(); }
      @Override public CompletableResultCode shutdown() { return CompletableResultCode.ofSuccess(); }
    };
    SdkLoggerProvider provider = SdkLoggerProvider.builder()
        .addLogRecordProcessor(SimpleLogRecordProcessor.create(exporter)).build();
    Logger logger = provider.get("probe");
    ExecutorService completers = Executors.newFixedThreadPool(exportsPerRound);
    int neverCompleted = 0;
    for (int round = 0; round < rounds; round++) {
      exports.clear();
      for (int i = 0; i < exportsPerRound; i++) logger.logRecordBuilder().setBody("line " + i).emit();
      CountDownLatch go = new CountDownLatch(1);
      for (CompletableResultCode export : new ArrayList<>(exports)) {
        completers.execute(() -> { try { go.await(); export.succeed(); } catch (InterruptedException e) { Thread.currentThread().interrupt(); } });
      }
      go.countDown(); // the exports complete while forceFlush() counts and iterates the pending set
      CompletableResultCode flush = provider.forceFlush();
      flush.join(1, TimeUnit.SECONDS);
      if (!flush.isDone()) {
        neverCompleted++;
        // every export is done and a fresh forceFlush() says so at once; only the first result is stuck
        if (!exports.stream().allMatch(CompletableResultCode::isSuccess) || !provider.forceFlush().isSuccess()) throw new AssertionError();
      }
    }
    System.out.printf("%d of %d forceFlush() results never completed although every export had completed (%d exports per round)%n",
        neverCompleted, rounds, exportsPerRound);
    completers.shutdownNow();
    provider.close();
    System.exit(0);
  }
}
javac -cp <opentelemetry-sdk-logs, -sdk-common, -api, -context, -common, -sdk-trace, -sdk-metrics, -api-incubator jars> ForceFlushRace.java
java  -cp <same> ForceFlushRace 2000 5

What did you expect to see?

Every forceFlush() result completes once the exports it covers have completed.

What did you see instead?

Results that never complete, while every export has succeeded and a fresh forceFlush() returns success immediately (the program asserts both). Counts from one laptop, 2000 rounds each; they vary with scheduling:

SDK 5 exports per round 1 export per round
1.67.0 86 / 2000 7 / 2000
1.65.0 94 / 2000 3 / 2000
1.49.0 64 / 1000 –

Also seen inside a CPU-limited Linux container, where the gap between size() and the iteration is stretched by scheduling.

What version and what artifacts are you using?

opentelemetry-sdk-logs, opentelemetry-sdk-common (the same pattern in opentelemetry-sdk-trace's SimpleSpanProcessor); versions 1.67.0, 1.65.0 and 1.49.0, referenced through opentelemetry-bom in Maven.

Environment

Compiler/runtime: Amazon Corretto 21.0.11 (also reproduced on Corretto 25)
OS: macOS 15; also Amazon Linux 2023 (container)

Additional context

Where it hurts: anything that flushes at a boundary with a bounded wait, for example an AWS Lambda handler that calls forceFlush().join(1, SECONDS) at the end of each invocation so the last records are exported before the environment is frozen. Each occurrence costs the full timeout for nothing.

A snapshot fixes it, since size() and the iteration then agree and every counted result gets its callback:

// SimpleLogRecordProcessor and SimpleSpanProcessor
public CompletableResultCode forceFlush() {
  return CompletableResultCode.ofAll(new ArrayList<>(pendingExports));
}

or, more defensively, ofAll could copy the collection it is given before counting.

Workaround for callers on current versions: re-arm forceFlush() in short steps within one overall deadline instead of a single long join (a fresh call snapshots the current set, and an empty set returns ofSuccess()), and stop when the thread is interrupted, because join returns immediately on an interrupted thread and preserves the flag.

Activity

  1. nikhilred2619 commented on Nov 1, 2026

    @nikhilred2619

    Hi @Jozef7467,

    I went through the issue, and the problem with the pending exports being modified while forceFlush() is processing them makes sense.

    I'd be happy to work on this. My plan would be to add a regression test for the concurrency issue and then make a focused fix for both SimpleLogRecordProcessor and SimpleSpanProcessor.

    Before I start, could you confirm whether anyone is already working on it and whether this approach looks good?

    I'm happy to implement it, run the relevant tests, and submit a PR for review.

    Thanks,
    Nikhil

  2. Jozef7467 commented on Nov 2, 2026

    @Jozef7467
    Author

    Hi. Nobody is working on it as far as I know, so go ahead. The approach matches what I had in mind. Assignment is up to the maintainers, of course. Happy to try the fix once the PR is up.

    Thanks for picking it up.

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions