JDK-8068693 : (ch) test java/nio/channels/AsyncCloseAndInterrupt.java failing
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.nio
  • Affected Version: 6u95,8u40,9
  • Priority: P4
  • Status: Closed
  • Resolution: Fixed
  • OS: windows
  • CPU: x86_64
  • Submitted: 2015-01-09
  • Updated: 2016-06-13
  • Resolved: 2016-04-12
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 9
9 b115Fixed
Related Reports
Relates :  
JDK-8151582 - (ch) test java/nio/channels/AsyncCloseAndInterrupt.java failing due to "Connection succeeded"
Relates :  
JDK-8156114 - java/nio/channels/AsyncCloseAndInterrupt.java fails intermittently: SocketChannel/finishConnect/close threw an exception
Relates :  
JDK-8153209 - java/nio/channels/AsyncCloseAndInterrupt.java fails throwing exception: java.nio.channels.ClosedChannelException
Relates :  
JDK-8153548 - java/nio/channels/AsyncCloseAndInterrupt.java fails with ClosedChannelException
Description
Test java/nio/channels/AsyncCloseAndInterrupt.java intermittently failed in 8u40  resman nightly with "timeout" error:

DatagramChannel/receive/close
Thrown as expected: java.nio.channels.AsynchronousCloseException

Pipe.SourceChannel/read/interrupt
java.lang.Exception: Pipe.SourceChannel/read/interrupt timed out
	at TestThread.finishAndThrow(TestThread.java:83)
	at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:602)
	at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:609)
	at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:632)
	at AsyncCloseAndInterrupt.main(AsyncCloseAndInterrupt.java:732)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:94)
	at java.lang.Thread.run(Thread.java:745)

JavaTest Message: Test threw exception: java.lang.Exception: Pipe.SourceChannel/read/interrupt timed out
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.Exception: Pipe.SourceChannel/read/interrupt timed out
Comments
RFR: http://mail.openjdk.java.net/pipermail/nio-dev/2016-April/003614.html jprt results: http://scaaa637.us.oracle.com/archive/2016/04/2016-04-05-114717.oracle.dev/logs/ run locally with 1000 run without failure.
06-04-2016
Root cause: for JDK-8068693, 500ms is too short on busy system for channel to be closed or for thread blocking on IO to be interrupted. for JDK-8153209, it's a test regression due to JDK-8151582 (http://hg.openjdk.java.net/jdk9/jdk9/jdk/rev/88577677aec9). There is a time window between thread ready and io operation ready, deleting the original sleep(100) might cause channel closed before accessing the channel. Suggested Fix: for JDK-8068693, increase the time from 500ms to 10000ms. for JDK-8153209, do not sleep when running tests for CONNECT/FINISH_CONNECT, sleep for other test cases.
06-04-2016
http://scaaa008.us.oracle.com:9502/runs/01358/1358513.CORELIBS-JDK-NIGHTLY-JTREG/1358513.CORELIBS-JDK-NIGHTLY-JTREG-11/20160322085739.1358513.CORELIBS-JDK-NIGHTLY-JTREG.regression-jdk-nio.jtreg/.workload.log http://scaaa008.us.oracle.com:9502/runs/01337/1337870.CORELIBS-JDK-NIGHTLY-JTREG/1337870.CORELIBS-JDK-NIGHTLY-JTREG-11/20160308093533.1337870.CORELIBS-JDK-NIGHTLY-JTREG.regression-jdk-nio.jtreg/.workload.log new type of issue on same test, temporarily tracked the issue in this bug java.io.IOException: Error creating fifo at AsyncCloseAndInterrupt.initFile(AsyncCloseAndInterrupt.java:136) at AsyncCloseAndInterrupt.main(AsyncCloseAndInterrupt.java:674) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:520) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110) at java.lang.Thread.run(Thread.java:804)
22-03-2016
the first issue listed above is tracked by this bug id, it occurred only on windows, there are 5 failures, 1 failed against 6u101b10, 3 of them failed against 1.8.0_40, 1 failed against 1.9.0. The latest failure happened at at 2015-05-13 is against 6u101b10. The issue never happened since then. Could I suggest to close this one? (second issue will be tracked and fixed by JDK-8151582) [~alanb]
20-03-2016
In fact there are 2 kinds of issue mixed in original bug JDK-8068693. 1. one occurred only on windows, there are 5 failures, 1 failed against 6u101b10, 3 of them failed against 1.8.0_40, 1 failed against 1.9.0. The latest failure happened at at 2015-05-13 is against 6u101b10. The issue never happened since then. Pipe.SourceChannel/read/interrupt java.lang.Exception: Pipe.SourceChannel/read/interrupt timed out at TestThread.finishAndThrow(TestThread.java:83) at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:602) at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:609) at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:632) at AsyncCloseAndInterrupt.main(AsyncCloseAndInterrupt.java:732) 2. another occurred only on linux, which are test related to FINISH_CONNECT and happened 6 times from 2015-11-10 to 2016-02-29. SocketChannel/finishConnect/close finishConnect wait for pumping refuser ... java.lang.Exception: SocketChannel/finishConnect/close threw an exception at TestThread.finishAndThrow(TestThread.java:80) at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:602) at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:622) at AsyncCloseAndInterrupt.main(AsyncCloseAndInterrupt.java:720) ... ... Caused by: java.lang.RuntimeException: Connection succeeded at AsyncCloseAndInterrupt$16.doIO(AsyncCloseAndInterrupt.java:374) at AsyncCloseAndInterrupt$Tester.go(AsyncCloseAndInterrupt.java:485) at TestThread.run(TestThread.java:55) The second one happened frequently recently, and we can make sure it's a test issue. To make the bug more clearer, I file a new bug to track the second issue, JDK-8151582
10-03-2016
Test fail with similar error on Mach5: #section:main ----------messages:(3/139)---------- command: main AsyncCloseAndInterrupt reason: User specified action: run main/othervm AsyncCloseAndInterrupt elapsed time (seconds): 6.937 ----------System.out:(0/0)---------- ----------System.err:(144/4761)---------- FileChannel/transferTo/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/transferTo/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException WARNING: transferTo/close not tested FileChannel/transferFrom/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/transferFrom/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException WARNING: transferFrom/close not tested FileChannel/read/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/read/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/read/close Thrown as expected: java.nio.channels.AsynchronousCloseException FileChannel/readv/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/readv/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/readv/close Thrown as expected: java.nio.channels.AsynchronousCloseException FileChannel/write/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/write/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/write/close Wrote 65536 bytes Channel closed FileChannel/writev/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/writev/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException FileChannel/writev/close Wrote 65536 bytes Channel closed SocketChannel/read/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/read/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/read/close Thrown as expected: java.nio.channels.AsynchronousCloseException SocketChannel/read/shutdown-input Read returned -1 Channel open, input shutdown SocketChannel/readv/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/readv/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/readv/close Thrown as expected: java.nio.channels.AsynchronousCloseException SocketChannel/readv/shutdown-input Read returned -1 Channel open, input shutdown SocketChannel/write/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/write/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/write/close Wrote 1351585 bytes Channel closed SocketChannel/write/shutdown-output Wrote 1351585 bytes Channel open, output shutdown SocketChannel/writev/interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/writev/pre-interrupt Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/writev/close Wrote 1351585 bytes Channel closed SocketChannel/writev/shutdown-output Wrote 1351585 bytes Channel open, output shutdown Wait for initial Pump Start pumping refuser ... SocketChannel/connect/interrupt connect wait for pumping refuser ... Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/connect/pre-interrupt connect wait for pumping refuser ... Thrown as expected: java.nio.channels.ClosedByInterruptException SocketChannel/connect/close connect wait for pumping refuser ... Thrown as expected: java.nio.channels.AsynchronousCloseException SocketChannel/finishConnect/interrupt finishConnect wait for pumping refuser ... java.lang.Exception: SocketChannel/finishConnect/interrupt threw an exception at TestThread.finishAndThrow(TestThread.java:80) at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:602) at AsyncCloseAndInterrupt.test(AsyncCloseAndInterrupt.java:609) at AsyncCloseAndInterrupt.main(AsyncCloseAndInterrupt.java:720) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:520) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:92) at java.lang.Thread.run(Thread.java:747) Caused by: java.lang.RuntimeException: Connection succeeded at AsyncCloseAndInterrupt$16.doIO(AsyncCloseAndInterrupt.java:374) at AsyncCloseAndInterrupt$Tester.go(AsyncCloseAndInterrupt.java:485) at TestThread.run(TestThread.java:55) JavaTest Message: Test threw exception: java.lang.Exception: SocketChannel/finishConnect/interrupt threw an exception JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.Exception: SocketChannel/finishConnect/interrupt threw an exception ----------rerun:(20/1850)*---------- HOME=/opt/mach5/mach5-one \\ LANG=en_US.UTF-8 \\ PATH=/bin:/usr/bin \\ buildid=BUILD_ID \\ CLASSPATH=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/mach5/jdkbuildwrapper/.data/unpacked/jpg/infra/builddeps/jtreg-4.1/1.3/jtreg/lib/javatest.jar:/scratch/jenkins/workspace/9-dev-tier2-linux-x64/mach5/jdkbuildwrapper/.data/unpacked/jpg/infra/builddeps/jtreg-4.1/1.3/jtreg/lib/jtreg.jar:/scratch/jenkins/workspace/9-dev-tier2-linux-x64/JTwork/jdk_test/classes/19/java/nio/channels:/scratch/jenkins/workspace/9-dev-tier2-linux-x64/jdk/test/java/nio/channels \\ /scratch/jenkins/workspace/9-dev-tier2-linux-x64/build/jdk/bin/java \\ -Dtest.class.path.prefix=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/JTwork/jdk_test/classes/19/java/nio/channels:/scratch/jenkins/workspace/9-dev-tier2-linux-x64/jdk/test/java/nio/channels \\ -Dtest.src=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/jdk/test/java/nio/channels \\ -Dtest.src.path=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/jdk/test/java/nio/channels \\ -Dtest.classes=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/JTwork/jdk_test/classes/19/java/nio/channels \\ -Dtest.class.path=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/JTwork/jdk_test/classes/19/java/nio/channels \\ -Dtest.vm.opts='-ea -esa -Xmx512m' \\ -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m' \\ -Dtest.compiler.opts= \\ -Dtest.java.opts= \\ -Dtest.jdk=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/build/jdk \\ -Dcompile.jdk=/scratch/jenkins/workspace/9-dev-tier2-linux-x64/build/jdk \\ -Dtest.timeout.factor=4.0 \\ -ea -esa -Xmx512m \\ com.sun.javatest.regtest.agent.MainWrapper /scratch/jenkins/workspace/9-dev-tier2-linux-x64/JTwork/jdk_test/classes/19/java/nio/channels/AsyncCloseAndInterrupt.jta result: Failed. Execution failed: `main' threw exception: java.lang.Exception: SocketChannel/finishConnect/interrupt threw an exception test result: Failed. Execution failed: `main' threw exception: java.lang.Exception: SocketChannel/finishConnect/interrupt threw an exception
11-11-2015