United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
JDK-8003895 : java/nio/channels/AsynchronousChannelGroup/Unbounded.java failing again [win64]

Details
Type:
Bug
Submit Date:
2012-11-22
Status:
Closed
Updated Date:
2014-09-04
Project Name:
JDK
Resolved Date:
2013-06-05
Component:
core-libs
OS:
Sub-Component:
java.nio
CPU:
Priority:
P4
Resolution:
Fixed
Affected Versions:
8
Fixed Versions:

Related Reports
Backport:
Backport:
Backport:
Backport:
Duplicate:

Sub Tasks

Description
This test has recently started to fail in JPRT, all sightings so far have been Windows 64-bit. The failure doesn't seem to be the test itself, it appears to be interference from tests that run previously, perhaps a connection limit. The test runs okay if changes to /othervm mode.

--------------------------------------------------
TEST: java/nio/channels/AsynchronousChannelGroup/Unbounded.java
JDK under test: (C:\jprt\products\P1\JDK8-L~1\JDK18~1.0)
java version "1.8.0-ea"
Java(TM) SE Runtime Environment (build 1.8.0-ea-b65)
Java HotSpot(TM) 64-Bit Server VM (build 25.0-b09, mixed mode)


ACTION: build -- Passed. Build successful
REASON: Named class compiled on demand
TIME:   0.109 seconds
messages:
command: build Unbounded
reason: Named class compiled on demand
elapsed time (seconds): 0.109

ACTION: compile -- Passed. Compilation successful
REASON: .class file out of date or does not exist
TIME:   0.109 seconds
messages:
command: compile C:\jprt\T\P1\103210.albatem\s\test\java\nio\channels\AsynchronousChannelGroup\Unbounded.java
reason: .class file out of date or does not exist
elapsed time (seconds): 0.109

ACTION: main -- Error. Timeout
REASON: Assumed action based on file name: run main Unbounded 
TIME:   480.825 seconds
messages:
command: main Unbounded
reason: Assumed action based on file name: run main Unbounded 
Timeout signalled after 480 seconds
elapsed time (seconds): 480.825
STDOUT:
Listener created.
All client connections established.
All read operations outstanding.
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
accepted: 241
queued: 241
Waiting for 15 remaining connections to be accepted
STDERR:
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
read failed: java.io.IOException: An existing connection was forcibly closed by the remote host
java.lang.InterruptedException
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2013)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2087)
	at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:391)
	at Unbounded.main(Unbounded.java:128)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:474)
	at com.sun.javatest.regtest.MainAction$SameVMRunnable.run(MainAction.java:698)
	at java.lang.Thread.run(Thread.java:722)

JavaTest Message: Test threw exception: java.lang.InterruptedException
JavaTest Message: shutting down test


TEST RESULT: Error. Timeout
--------------------------------------------------
                                    

Comments
I've unable to duplicate this issue on a local Windows 64-bit machine, also it does not duplicate in TL nightly. From the data so far it appears to be a resource issue, perhaps caused by running in agent VM and previous tests leaving a lot of threads or connections open. We can easily "fix" the failure by running it in othervm mode, but further analysis will be required on the JPRT  machine to narrow this one down.
                                     
2012-11-24
URL:   http://hg.openjdk.java.net/jdk8/tl/jdk/rev/8a9f897a57d6
User:  alanb
Date:  2013-06-05 10:14:35 +0000

                                     
2013-06-05
I have reproduced this issue running the test in standalone mode ( outside of jtreg ). It fails very rarely. I think there is a race to fill the
listeners backlog.

To help give some support to the theory that this is a race, I hacked the testcase to remove the accept calls ( emulate slow acceptance
of these sockets ). At more than 51 connections the problem can be seen, I am guessing that this is one more than the default backlog
value. Using the bind(SocketAddress, int) and providing a sufficient backlog resolves the problem. I would like to take this test off the 
problem list and pass a value of CONCURRENCY_COUNT to the listeners backlog.
                                     
2012-11-30
URL:   http://hg.openjdk.java.net/jdk8/jdk8/jdk/rev/8a9f897a57d6
User:  lana
Date:  2013-06-11 18:41:37 +0000

                                     
2013-06-11
7u60-critical-approved: Dev/sustaining has automatic SQE approval for test only fixes as per http://wiki.se.oracle.com/display/JPG/SQE+approval+policy+on+regression+test+ONLY+fixes+in+update+releases.
                                     
2014-01-22



Hardware and Software, Engineered to Work Together