From 10b8a432910b6630d05ef4c03fbe88cc88b1983c Mon Sep 17 00:00:00 2001 From: Daniel Schmidt Date: Wed, 6 Aug 2025 17:56:48 +0200 Subject: [PATCH 1/2] Fix race condition in OutputCapture Update `OutputCapture` to fix a race condition that could occur due to the cache. Prior to this commit, when data was written whilst simultaneously being read, any subsequent reading of data might miss the last output. See gh-46685 Signed-off-by: Daniel Schmidt --- .../boot/test/system/OutputCapture.java | 36 +++++++---- .../boot/test/system/OutputCaptureTests.java | 63 ++++++++++++++++++- 2 files changed, 87 insertions(+), 12 deletions(-) diff --git a/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java b/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java index 9770eba290a..302987ce845 100644 --- a/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java +++ b/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java @@ -23,6 +23,7 @@ import java.util.ArrayDeque; import java.util.ArrayList; import java.util.Deque; import java.util.List; +import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; import java.util.function.Consumer; import java.util.function.Predicate; @@ -40,6 +41,7 @@ import org.springframework.util.ClassUtils; * @author Phillip Webb * @author Andy Wilkinson * @author Sam Brannen + * @author Daniel Schmidt * @see OutputCaptureExtension * @see OutputCaptureRule */ @@ -49,11 +51,14 @@ class OutputCapture implements CapturedOutput { private AnsiOutputState ansiOutputState; - private final AtomicReference out = new AtomicReference<>(null); + private final AtomicLong outVersion = new AtomicLong(); + private final AtomicReference out = new AtomicReference<>(null); - private final AtomicReference err = new AtomicReference<>(null); + private final AtomicLong errVersion = new AtomicLong(); + private final AtomicReference err = new AtomicReference<>(null); - private final AtomicReference all = new AtomicReference<>(null); + private final AtomicLong allVersion = new AtomicLong(); + private final AtomicReference all = new AtomicReference<>(null); /** * Push a new system capture session onto the stack. @@ -106,7 +111,7 @@ class OutputCapture implements CapturedOutput { */ @Override public String getAll() { - return get(this.all, (type) -> true); + return get(this.all, this.allVersion, (type) -> true); } /** @@ -115,7 +120,7 @@ class OutputCapture implements CapturedOutput { */ @Override public String getOut() { - return get(this.out, Type.OUT::equals); + return get(this.out, this.outVersion, Type.OUT::equals); } /** @@ -124,7 +129,7 @@ class OutputCapture implements CapturedOutput { */ @Override public String getErr() { - return get(this.err, Type.ERR::equals); + return get(this.err, this.errVersion, Type.ERR::equals); } /** @@ -136,19 +141,24 @@ class OutputCapture implements CapturedOutput { } void clearExisting() { + this.outVersion.incrementAndGet(); this.out.set(null); + this.errVersion.incrementAndGet(); this.err.set(null); + this.allVersion.incrementAndGet(); this.all.set(null); } - private String get(AtomicReference existing, Predicate filter) { + private String get(AtomicReference resultCache, AtomicLong version, Predicate filter) { Assert.state(!this.systemCaptures.isEmpty(), "No system captures found. Please check your output capture registration."); - String result = existing.get(); - if (result == null) { - result = build(filter); - existing.compareAndSet(null, result); + long currentVersion = version.get(); + VersionedCacheResult cached = resultCache.get(); + if (cached != null && cached.version == currentVersion) { + return cached.result; } + String result = build(filter); + resultCache.compareAndSet(null, new VersionedCacheResult(result, currentVersion)); return result; } @@ -160,6 +170,10 @@ class OutputCapture implements CapturedOutput { return builder.toString(); } + private record VersionedCacheResult(String result, long version) { + + } + /** * A capture session that captures {@link System#out System.out} and {@link System#out * System.err}. diff --git a/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java b/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java index 53d31364b15..b9fb7e680a7 100644 --- a/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java +++ b/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java @@ -19,8 +19,13 @@ package org.springframework.boot.test.system; import java.io.ByteArrayOutputStream; import java.io.PrintStream; import java.util.NoSuchElementException; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.TimeUnit; import java.util.function.Predicate; +import org.jspecify.annotations.Nullable; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; @@ -32,6 +37,7 @@ import static org.assertj.core.api.Assertions.assertThatExceptionOfType; * Tests for {@link OutputCapture}. * * @author Phillip Webb + * @author Daniel Schmidt */ class OutputCaptureTests { @@ -188,6 +194,45 @@ class OutputCaptureTests { assertThat(this.output.buildCount).isEqualTo(2); } + @Test + void getOutCacheShouldNotReturnStaleDataWhenDataIsLoggedWhileReading() throws Exception { + this.output.push(); + System.out.print("A"); + this.output.waitAfterBuildLatch = new CountDownLatch(1); + + ExecutorService executorService = null; + try { + executorService = Executors.newFixedThreadPool(2); + var readingThreadFuture = executorService.submit(() -> { + // this will release the releaseAfterBuildLatch and block on the waitAfterBuildLatch + assertThat(this.output.getOut()).isEqualTo("A"); + }); + var writingThreadFuture = executorService.submit(() -> { + // wait until we finished building the first result (but did not yet update the cache) + try { + this.output.releaseAfterBuildLatch.await(); + } + catch (InterruptedException e) { + throw new RuntimeException(e); + } + // print something else and then release the latch, for the other thread to continue + System.out.print("B"); + this.output.waitAfterBuildLatch.countDown(); + }); + readingThreadFuture.get(); + writingThreadFuture.get(); + } + finally { + if (executorService != null) { + executorService.shutdown(); + executorService.awaitTermination(10, TimeUnit.SECONDS); + } + } + + // If not synchronized correctly this will fail, because the second print did not clear the cache and the cache will return stale data. + assertThat(this.output.getOut()).isEqualTo("AB"); + } + private void pushAndPrint() { this.output.push(); System.out.print("A"); @@ -212,10 +257,26 @@ class OutputCaptureTests { int buildCount; + @Nullable + CountDownLatch waitAfterBuildLatch = null; + + CountDownLatch releaseAfterBuildLatch = new CountDownLatch(1); + @Override String build(Predicate filter) { this.buildCount++; - return super.build(filter); + var result = super.build(filter); + this.releaseAfterBuildLatch.countDown(); + if (this.waitAfterBuildLatch != null) { + try { + this.waitAfterBuildLatch.await(); + } + catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new RuntimeException(e); + } + } + return result; } } From 742bcc568d25d38f6a0b94d0412ca77748de10ca Mon Sep 17 00:00:00 2001 From: Phillip Webb Date: Fri, 8 Aug 2025 13:10:30 +0100 Subject: [PATCH 2/2] Polish 'Fix race condition in OutputCapture' See gh-46685 --- .../boot/test/system/OutputCapture.java | 52 +++++------ .../boot/test/system/OutputCaptureTests.java | 90 +++++++++---------- 2 files changed, 69 insertions(+), 73 deletions(-) diff --git a/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java b/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java index 302987ce845..73810d26a57 100644 --- a/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java +++ b/spring-boot-project/spring-boot-test/src/main/java/org/springframework/boot/test/system/OutputCapture.java @@ -23,7 +23,6 @@ import java.util.ArrayDeque; import java.util.ArrayList; import java.util.Deque; import java.util.List; -import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; import java.util.function.Consumer; import java.util.function.Predicate; @@ -51,14 +50,15 @@ class OutputCapture implements CapturedOutput { private AnsiOutputState ansiOutputState; - private final AtomicLong outVersion = new AtomicLong(); - private final AtomicReference out = new AtomicReference<>(null); + private final AtomicReference out = new AtomicReference<>(); - private final AtomicLong errVersion = new AtomicLong(); - private final AtomicReference err = new AtomicReference<>(null); + private final AtomicReference err = new AtomicReference<>(); - private final AtomicLong allVersion = new AtomicLong(); - private final AtomicReference all = new AtomicReference<>(null); + private final AtomicReference all = new AtomicReference<>(); + + OutputCapture() { + clearExisting(); + } /** * Push a new system capture session onto the stack. @@ -111,7 +111,7 @@ class OutputCapture implements CapturedOutput { */ @Override public String getAll() { - return get(this.all, this.allVersion, (type) -> true); + return get(this.all, (type) -> true); } /** @@ -120,7 +120,7 @@ class OutputCapture implements CapturedOutput { */ @Override public String getOut() { - return get(this.out, this.outVersion, Type.OUT::equals); + return get(this.out, Type.OUT::equals); } /** @@ -129,7 +129,7 @@ class OutputCapture implements CapturedOutput { */ @Override public String getErr() { - return get(this.err, this.errVersion, Type.ERR::equals); + return get(this.err, Type.ERR::equals); } /** @@ -141,25 +141,21 @@ class OutputCapture implements CapturedOutput { } void clearExisting() { - this.outVersion.incrementAndGet(); - this.out.set(null); - this.errVersion.incrementAndGet(); - this.err.set(null); - this.allVersion.incrementAndGet(); - this.all.set(null); + this.out.set(new NoOutput()); + this.err.set(new NoOutput()); + this.all.set(new NoOutput()); } - private String get(AtomicReference resultCache, AtomicLong version, Predicate filter) { + private String get(AtomicReference existing, Predicate filter) { Assert.state(!this.systemCaptures.isEmpty(), "No system captures found. Please check your output capture registration."); - long currentVersion = version.get(); - VersionedCacheResult cached = resultCache.get(); - if (cached != null && cached.version == currentVersion) { - return cached.result; + Object existingOutput = existing.get(); + if (existingOutput instanceof String) { + return (String) existingOutput; } - String result = build(filter); - resultCache.compareAndSet(null, new VersionedCacheResult(result, currentVersion)); - return result; + String builtOutput = build(filter); + existing.compareAndSet(existingOutput, builtOutput); + return builtOutput; } String build(Predicate filter) { @@ -170,10 +166,6 @@ class OutputCapture implements CapturedOutput { return builder.toString(); } - private record VersionedCacheResult(String result, long version) { - - } - /** * A capture session that captures {@link System#out System.out} and {@link System#out * System.err}. @@ -353,4 +345,8 @@ class OutputCapture implements CapturedOutput { } + static class NoOutput { + + } + } diff --git a/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java b/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java index b9fb7e680a7..1e5969ed5f7 100644 --- a/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java +++ b/spring-boot-project/spring-boot-test/src/test/java/org/springframework/boot/test/system/OutputCaptureTests.java @@ -22,10 +22,10 @@ import java.util.NoSuchElementException; import java.util.concurrent.CountDownLatch; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; +import java.util.concurrent.Future; import java.util.concurrent.TimeUnit; import java.util.function.Predicate; -import org.jspecify.annotations.Nullable; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; @@ -196,41 +196,21 @@ class OutputCaptureTests { @Test void getOutCacheShouldNotReturnStaleDataWhenDataIsLoggedWhileReading() throws Exception { - this.output.push(); + TestLatchedOutputCapture output = new TestLatchedOutputCapture(); + output.push(); System.out.print("A"); - this.output.waitAfterBuildLatch = new CountDownLatch(1); - - ExecutorService executorService = null; + ExecutorService executor = Executors.newFixedThreadPool(2); try { - executorService = Executors.newFixedThreadPool(2); - var readingThreadFuture = executorService.submit(() -> { - // this will release the releaseAfterBuildLatch and block on the waitAfterBuildLatch - assertThat(this.output.getOut()).isEqualTo("A"); - }); - var writingThreadFuture = executorService.submit(() -> { - // wait until we finished building the first result (but did not yet update the cache) - try { - this.output.releaseAfterBuildLatch.await(); - } - catch (InterruptedException e) { - throw new RuntimeException(e); - } - // print something else and then release the latch, for the other thread to continue - System.out.print("B"); - this.output.waitAfterBuildLatch.countDown(); - }); - readingThreadFuture.get(); - writingThreadFuture.get(); + Future reader = executor.submit(output::releaseAfterBuildAndAssertResultIsA); + Future writer = executor.submit(output::awaitReleaseAfterBuildThenWriteBAndRelease); + reader.get(); + writer.get(); } finally { - if (executorService != null) { - executorService.shutdown(); - executorService.awaitTermination(10, TimeUnit.SECONDS); - } + executor.shutdown(); + executor.awaitTermination(10, TimeUnit.SECONDS); } - - // If not synchronized correctly this will fail, because the second print did not clear the cache and the cache will return stale data. - assertThat(this.output.getOut()).isEqualTo("AB"); + assertThat(output.getOut()).isEqualTo("AB"); } private void pushAndPrint() { @@ -257,28 +237,48 @@ class OutputCaptureTests { int buildCount; - @Nullable - CountDownLatch waitAfterBuildLatch = null; + @Override + String build(Predicate filter) { + this.buildCount++; + return super.build(filter); + } + + } + + static class TestLatchedOutputCapture extends OutputCapture { - CountDownLatch releaseAfterBuildLatch = new CountDownLatch(1); + private final CountDownLatch waitAfterBuild = new CountDownLatch(1); + + private final CountDownLatch releaseAfterBuild = new CountDownLatch(1); @Override String build(Predicate filter) { - this.buildCount++; var result = super.build(filter); - this.releaseAfterBuildLatch.countDown(); - if (this.waitAfterBuildLatch != null) { - try { - this.waitAfterBuildLatch.await(); - } - catch (InterruptedException e) { - Thread.currentThread().interrupt(); - throw new RuntimeException(e); - } - } + this.releaseAfterBuild.countDown(); + await(this.waitAfterBuild); return result; } + void releaseAfterBuildAndAssertResultIsA() { + assertThat(getOut()).isEqualTo("A"); + } + + void awaitReleaseAfterBuildThenWriteBAndRelease() { + await(this.releaseAfterBuild); + System.out.print("B"); + this.waitAfterBuild.countDown(); + } + + private void await(CountDownLatch latch) { + try { + latch.await(); + } + catch (InterruptedException ex) { + Thread.currentThread().interrupt(); + throw new RuntimeException(ex); + } + } + } }