Bug ID: JDK-8333358 java/io/IO/IO.java test fails intermittently

JDK-8333358 : java/io/IO/IO.java test fails intermittently

Type: Bug
Component: core-libs
Sub-Component: java.io
Affected Version: 23,24

Priority: P3
Status: Resolved
Resolution: Fixed
OS: linux,os_x
CPU: generic

Submitted: 2024-05-31
Updated: 2024-07-15
Resolved: 2024-06-20

Versions (Unresolved/Resolved/Fixed)

The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.

JDK 23	JDK 24
23Fixed	24 b04Fixed

Related Reports

Relates :

JDK-8305457 - Implement java.io.IO

Description

org.opentest4j.AssertionFailedError: expected: <0> but was: <1>
	at org.junit.jupiter.api.AssertionFailureBuilder.build(AssertionFailureBuilder.java:151)
	at org.junit.jupiter.api.AssertionFailureBuilder.buildAndThrow(AssertionFailureBuilder.java:132)
	at org.junit.jupiter.api.AssertEquals.failNotEqual(AssertEquals.java:197)
	at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:150)
	at org.junit.jupiter.api.AssertEquals.assertEquals(AssertEquals.java:145)
	at org.junit.jupiter.api.Assertions.assertEquals(Assertions.java:531)
	at IO$OSSpecificTests.inputTestInteractive(IO.java:133)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:197)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:1024)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:570)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:560)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:265)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:636)
	at java.base/java.util.stream.ReferencePipeline$7$1FlatMap.accept(ReferencePipeline.java:294)
	at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:1024)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:570)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:560)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:265)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:636)
	at java.base/java.util.stream.ReferencePipeline$7$1FlatMap.accept(ReferencePipeline.java:294)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:1024)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:570)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:560)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:265)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:636)
	at java.base/java.util.stream.ReferencePipeline$7$1FlatMap.accept(ReferencePipeline.java:294)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:215)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1709)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:570)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:560)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:265)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:636)
	at java.base/java.util.stream.ReferencePipeline$7$1FlatMap.accept(ReferencePipeline.java:294)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1709)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:570)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:560)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:265)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:636)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)
FAILED     IO$OSSpecificTests::inputTestInteractive '[1] null, null'

Comments

A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/19847 Date: 2024-06-23 15:11:52 +0000
23-06-2024
Changeset: 1b1dba80 Author: Pavel Rappo <prappo@openjdk.org> Date: 2024-06-20 16:28:48 +0000 URL: https://git.openjdk.org/jdk/commit/1b1dba8082969244effa86ac03c6053b3b0ddc43
20-06-2024
> or we can push it as is and let you file a separate "ProblemList java/io/IO/IO.java" issue, if you are unsuccessful in solving this issue by reconfiguring your environment. Please push it as it is.
20-06-2024
Matthias, I was wondering how you want to proceed. We can problem list your specific configuration in this PR, which feels suboptimal, or we can push it as is and let you file a separate "ProblemList java/io/IO/IO.java" issue, if you are unsuccessful in solving this issue by reconfiguring your environment.
20-06-2024
> I see -avm -conc:15 in the run log of the jtreg tier, that should be the concurrency. So that would mean at most 15 tests running concurrently on that system (which is on the higher side compared to what we have in our internal CI). This also reminds of a similar issue (but for Windows) that we recently discussed here https://github.com/openjdk/jdk/pull/17625#issuecomment-1952574423. I see that you have proposed problem listing this test for linux-ppc64le. I'll let you and Pavel decide that detail, but if you have some time and would like to investigate this further, then maybe you could try and reduce the concurrency when running this specific test by using the options discussed in that other PR and see if it helps? It's mostly to understand what the root cause of this issue is. If you wouldn't want to try that at this point in time, that's fine too.
18-06-2024
I see -avm -conc:15 in the run log of the jtreg tier, that should be the concurrency.
18-06-2024
Hello Matthias [~mbaesken], as an additional detail - what is the jtreg concurrency being used for running these tests on the failing setups?
18-06-2024
> With the latest PR, we still see the test failing on linuxppc64le. The macOS error we saw previously seem to be gone however. I'll be waiting for the usual jtr files from you. Thanks.
18-06-2024
With the latest PR, we still see the test failing on linuxppc64le. The macOS error we saw previously seem to be gone however.
18-06-2024
Matthias sent me yet another set of jtr files. Notably, captured tests routinely take 15 seconds and occasionally exceed 20 seconds. For comparison, on my personal machine, on average these tests take 400 ms. I pushed a commit to the PR that disables expect timeout entirely. Having seen test.timeout.factor=9.0 in the received jtr files, I hope that the default jtreg timeout of 120 seconds multiplied by 9, which amounts to 18 minutes, will be enough. Matthias, please test the latest patch from the PR and report here. Thanks for your help.
12-06-2024
The failure frequency seems to be the same.
12-06-2024
> Unfortunately the failures still occur even with the patch (on macOS x64 and on Linux ppc64le). Please provide the respective jtr files. Also, have you noticed if the frequency of failures has changed?
11-06-2024
> Great, if you have a PR ready we can test it in our test infrastructure . Unfortunately the failures still occur even with the patch (on macOS x64 and on Linux ppc64le).
11-06-2024
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/19627 Date: 2024-06-10 12:29:32 +0000
10-06-2024
> I'll prepare a PR that sets the timeout to 20 seconds and applies some additional improvements to the test. Great, if you have a PR ready we can test it in our test infrastructure .
10-06-2024
Changed the issue title to better describe what happens: "expected: <0> but was: <1>" is not the only type of failure seen in the jtr files. Another failure is "expected: <true> but was: <false>".
10-06-2024
I received another email from Matthias with a couple of jtr files capturing test failures after the diagnostic patch, which I provided earlier, has been applied. Looking at those files, the only explanation for the failures I could come up with was that the default `expect` timeout of _10 seconds_ is sometimes insufficient. I'll prepare a PR that sets the timeout to 20 seconds and applies some additional improvements to the test.
07-06-2024
I received an email from Matthias with a couple of jtr files: one for Linux and another one for macOS. From what I saw, the configuration of the systems was unremarkable, but in all failure cases STDOUT contents were surprising. When expect(1) was involved, regardless of the specific JDK console implementation, _sometimes_ a spawned process would not output anything to STDOUT. It's as if the output was not flushed. Other times, with expect(1), the test would pass, but only for the java.base console implementation, not JLine. I'm not sure if that is incidental or not. I'm preparing a patch to send to Matthias. That patch would provide more diagnostic output to help me debug the issue.
05-06-2024
Provided more info about Linux and macOS failures to Pavel.
04-06-2024
I would appreciate it if you could provide more of the test output than that stacktrace. You should remove all sensitive information though. Thanks.
31-05-2024
One test machine where it fails has /usr/bin/expect -v expect version 5.45 another : /usr/bin/expect -v expect version 5.45.4 (just in case, not sure if this matters)
31-05-2024
The new test generates a lot of errors since it has been introduced. Probably it should we problem-listed for now.
31-05-2024