Skip to content

Flaky test: BlockingPipedOutputStreamTest.testPipedStream — double close() races on a full capacity-1 queue #3055

Description

@polyglotAI-bot

Description

com.clickhouse.data.stream.BlockingPipedOutputStreamTest.testPipedStream (module clickhouse-data) fails intermittently with IOException: Close stream timed out after 10000 ms. Because clickhouse-data is built upstream of every other module, the single failure cascades — downstream modules then fail with error: module not found: com.clickhouse.data and the whole job goes red on PRs that do not touch stream code.

Each failure costs the job a full 10 seconds (the close timeout) before it reports.

Steps to reproduce

  1. Build clickhouse-data.
  2. Run BlockingPipedOutputStreamTest repeatedly under CPU contention (the failure does not appear on an idle machine). On a 4-vCPU container: 8 concurrent copies of the test class plus 4 busy-loop processes.
  3. Roughly 1 run in 3 fails.

Observed rate in our environment:

  • 8/8 sequential runs on an idle box: 0 failures
  • 24 runs across 3 rounds of 8 parallel copies + 4 CPU burners: 8 failures (33%)

Error Log or Exception StackTrace

[ERROR] com.clickhouse.data.stream.BlockingPipedOutputStreamTest.testPipedStream -- Time elapsed: 10.03 s <<< FAILURE!
[ERROR]   BlockingPipedOutputStreamTest.testPipedStream:281 » IO Close stream timed out after 10000 ms
[ERROR] Tests run: 1665, Failures: 1, Errors: 0, Skipped: 113

Line 281 is the closing brace of the try (InputStream in = ...; OutputStream out = stream) block — the exception comes from the implicit out.close(), not from an assertion.

Evidence of non-determinism (CI)

Two failing runs on unrelated PRs, neither of which touches clickhouse-data stream code:

  1. PR [jdbc-v1] Fix flaky testAsyncInsert: pin the async insert buffer instead of racing the flush #3054 (head 402053c5, a test-only change to ClickHouseStatementTest in jdbc-v1) — check SonarCloud:
    https://github.com/ClickHouse/clickhouse-java/actions/runs/31821990082/job/94837178240
  2. PR feat(client-v2, jdbc-v2): add MultiPoint data type support #3050 (head 58487f56, client-v2/jdbc-v2 MultiPoint) — check Java client ( clickhouse-http-client ) + CH 25.8:
    https://github.com/ClickHouse/clickhouse-java/actions/runs/31685663656/job/94401691572

On both runs the other 1664 tests passed, and other jobs on the same commit ran the same suite green — the failure appears and disappears with no code change.

Root cause

BlockingPipedOutputStream.close() is called twice on the same stream, and it is not idempotent under concurrency.

In the test, the writer task closes the stream when it finishes writing (BlockingPipedOutputStreamTest.java:236), and the main thread closes it again through try-with-resources once the latch drops (:281).

BlockingPipedOutputStream.close() (clickhouse-data/src/main/java/com/clickhouse/data/stream/BlockingPipedOutputStream.java:107-132):

public void close() throws IOException {
    if (closed) {          // <-- check
        return;
    }
    ...
    if (!queue.offer(ClickHouseByteBuffer.EMPTY_BUFFER, timeout, TimeUnit.MILLISECONDS)) {
        throw new IOException(... "Close stream timed out after %d ms" ...);
    }
    ...
    } finally {
        closed = true;     // <-- set, only AFTER the blocking offer
    }
}

closed is volatile, but the check-and-set is not atomic and closed is assigned only after the blocking offer. So while the writer thread is still inside its close(), the main thread can pass the if (closed) guard and enter close() as well, sending a second EMPTY_BUFFER into a queue whose reader has already reached EOF and stopped consuming. With queueLength == 1 the queue is full and no consumer remains, so the redundant offer waits out the whole 10 s timeout and throws.

Instrumenting the failure confirms this exactly. In every observed failure:

PROBE FAIL bufferSize=7 queueLength=1 queue.size=1 streamClosed=true
           msg=Close stream timed out after 10000 ms p=10001 n=0 latch=0 writerDone=1
  • queueLength=1 in every failure — the smallest bounded ArrayBlockingQueue, i.e. the tightest race window (the unbounded LinkedBlockingQueue cases never fail).
  • queue.size=1 — the queue is full and nothing will drain it.
  • writerDone=1, p=10001, n=0, latch=0 — writer and reader both completed cleanly; the data transfer itself was correct.
  • streamClosed=true — the stream was already closed when the offer failed. This is the direct proof that the if (closed) return guard was bypassed: a second close() was in flight on a stream that is now marked closed.
  • Both pool threads were idle (WAITING for work) at the moment of failure — there is no deadlock, only an offer waiting for a consumer that has gone.

The race window is very small, which is why the test is green on an idle machine and only loses on loaded CI runners.

Expected Behaviour

Closing an already-closed (or concurrently-closing) BlockingPipedOutputStream should be a no-op, not a blocking write of a second EOF marker. close() should be idempotent, as Closeable#close requires:

If the stream is already closed then invoking this method has no effect.

Suggested fix

Make the close path atomic rather than adding a retry or a longer timeout in the test:

  • Make BlockingPipedOutputStream.close() synchronized, or gate it on an atomic compare-and-set (e.g. move closed to an AtomicBoolean and enter the body only if compareAndSet(false, true) wins). Either way, mark the stream closed before the blocking offer, so that a concurrent second close() returns immediately rather than queuing another EMPTY_BUFFER.
  • Contrast case that must keep working: the first close must still flush the pending buffer and enqueue exactly one EMPTY_BUFFER, so a reader still sees EOF; and a close() that legitimately blocks because a slow reader has not drained the queue yet must still time out with the current message.

Please note the same non-idempotent close pattern is worth checking in the sibling NonBlockingPipedOutputStream, and that this is not purely test debt: any application that closes the stream from its writer thread and also relies on try-with-resources in the calling thread can hit the same 10 s stall. BlockingPipedOutputStream is @Deprecated, so a maintainer may prefer to fix the test only — but the underlying close() is genuinely not thread-safe.

Configuration

Environment

  • Client version: main @ 1a117560
  • Language version: OpenJDK 17.0.19
  • OS: Ubuntu 24.04 container, 4 vCPU

ClickHouse Server

  • Not involved — clickhouse-data unit test, no server interaction.

Found by our PR monitor, which saw this same test fail on two unrelated PRs (#3054, #3050) while it was watching our own PRs, then verified and instrumented locally under CPU contention.

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions