Error reading stream exception thrown from OutputFilter / NativeImageBuildStep

[rsvoboda]

Describe the bug

Error reading stream exception thrown from OutputFilter / NativeImageBuildStep

We see this issue with Quarkus 2.13

https://github.com/quarkusio/quarkus/blob/main/core/deployment/src/main/java/io/quarkus/deployment/OutputFilter.java was refactored / introduced in #26892 / Quarkus 2.13.0.Final

Stacktrace:

[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildStep] Building native image from /home/runner/work/quarkus-startstop/quarkus-startstop/app-jax-rs-minimal/target/quarkus-native-image-source-jar/quarkus-runner.jar
[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildContainerRunner] Using docker to run the native image builder
Exception in thread "Process stdout" java.lang.RuntimeException: Error reading stream.
	at io.quarkus.deployment.OutputFilter.lambda$apply$0(OutputFilter.java:23)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.io.IOException: Stream closed
	at java.base/java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:176)
	at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:342)
	at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
	at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
	at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
	at java.base/java.io.InputStreamReader.read(InputStreamReader.java:181)
	at java.base/java.io.BufferedReader.fill(BufferedReader.java:161)
	at java.base/java.io.BufferedReader.readLine(BufferedReader.java:326)
	at java.base/java.io.BufferedReader.readLine(BufferedReader.java:392)
	at io.quarkus.deployment.OutputFilter.lambda$apply$0(OutputFilter.java:19)
	... 1 more
[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildContainerRunner] Checking image status quay.io/quarkus/ubi-quarkus-native-image:22.2-java17

Example logs: https://github.com/quarkus-qe/quarkus-startstop/actions/runs/3313239997 - see ci-artifacts and explore the directory structure of the zipped content. Alternatively click on Linux - Native build to see which test failed.

Issues is not regularly reproducible, we see it in daily GitHub action.

https://github.com/quarkus-qe/quarkus-startstop/actions/workflows/ci.yaml

Expected behavior

No error

Actual behavior

~50% of StartStopTS runs hit at least one "Exception in thread "Process stdout" java.lang.RuntimeException: Error reading stream." during native build executions. There are 8 compilations into native binary in one TS run.

How to Reproduce?

https://github.com/quarkus-qe/quarkus-startstop/actions/workflows/ci.yaml

https://github.com/quarkus-qe/quarkus-startstop/blob/main/.github/workflows/ci.yaml#L60

Output of uname -a or ver

No response

Output of java -version

Java 11

GraalVM version (if different from Java)

ubi-quarkus-native-image:22.2-java17

Quarkus version or git rev

2.13.3.Final

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

No response

[geoand]

@zakkak any ideas about this one?

[rsvoboda]

Getting the details using gh command

for i in `gh run list --repo quarkus-qe/quarkus-startstop --limit 40 | cut -f 7`; do 
   echo "${i} `gh run view --repo quarkus-qe/quarkus-startstop ${i} --log | grep "Process stdout" | wc -l`";
done

[rsvoboda]

This one is strange, I'm trying to reproduce the problem using standalone app https://github.com/rsvoboda/code-with-quarkus and I didn't see the fail in 50 runs

REPO=rsvoboda/code-with-quarkus
for i in `gh run list --repo ${REPO} --limit 50 | cut -f 7`; do 
   echo "${i} `gh run view --repo ${REPO} ${i} --log | grep "Process stdout" | wc -l`";
done

About the IOException: Stream closed, I don't think there is easy way to detect that InputStream is closed before reading from it. Maybe we could use available method https://docs.oracle.com/en/java/javase/17/docs/api/java.base/java/io/InputStream.html#available() (returns 0 and subclasses need to override it).

[geoand]

About the IOException: Stream closed, I don't think there is easy way to detect that InputStream is closed before reading from it. Maybe we could use available method https://docs.oracle.com/en/java/javase/17/docs/api/java.base/java/io/InputStream.html#available() (returns 0 and subclasses need to override it).

We could also just ignore the error when the stream is closed and try to continue.

[rsvoboda]

I can prepare that change, and let's see if @zakkak and you are ok with that.

[zakkak]

@rsvoboda are you sure this is not a github runner issue?

It's not clear to me if you managed to reproduce outside of github actions.

[rsvoboda]

Sofar we've seen this just on GH actions.

Update: Did 10 runs on our Jenkins with RHEL workers and hit the issue in 2 runs.