[
https://issues.jboss.org/browse/AS7-5967?page=com.atlassian.jira.plugin.s...
]
Brian Stansberry edited comment on AS7-5967 at 11/21/12 9:51 PM:
-----------------------------------------------------------------
When this fails, is it ever the first test executed that fails, or is it always the 2nd or
third?
I'm concerned this patch is covering over a race condition.
If you look at your trace logging, you can see that the DEBUG stack trace shows the
javax.naming.InitialContext has a ref to the RemoteContext. The test execution stack has a
reference to the InitialContext, even without your patch. This is sufficient to keep the
RemoteContext from being gc'd, unless the JVM is fundamentally broken (unlikely in the
extreme.)
The patch creating a local variable reference to the RemoteContext is just another form of
reference on the stack and shouldn't be preventing the RemoteContext being gc'd,
since it shouldn't be gc'd anyway.
I suspect what the patch is really doing that solves the intermittent failure is calling
context.close(). That means each test method is cleaning up the context. I'm concerned
what was happening before is a race condition. Test method #1 uses a RemoteContext, and
then it gets closed by the gc. There's a race with the next test method #2 creating a
new RemoteContext using the same underlying endpoint (which is cached and would be reused
by the 2nd test if the 1st hasn't cleaned up yet.) Looking at the code in
RemoteContext EndpointCache I don't see how this could happen though.
was (Author: brian.stansberry):
When this fails, is it ever the first test executed that fails, or is it always the
2nd or third?
I'm concerned this patch is covering over a race condition.
If you look at your trace logging, you can see that the DEBUG stack trace shows the
javax.naming.InitialContext has a ref to the RemoteContext. The test execution stack will
also have a reference, even without your patch. Either one of these references is
sufficient to keep the RemoteContext from being gc'd, unless the JVM is fundamentally
broken (unlikely in the extreme.)
The patch creating a local variable reference to the RemoteContext is just another form of
reference on the stack and shouldn't be preventing the RemoteContext being gc'd,
since it shouldn't be gc'd anyway.
I suspect what the patch is really doing that solves the intermittent failure is calling
context.close(). That means each test method is cleaning up the context. I'm concerned
what was happening before is a race condition. Test method #1 uses a RemoteContext, and
then it gets closed by the gc. There's a race with the next test method #2 creating a
new RemoteContext using the same underlying endpoint (which is cached and would be reused
by the 2nd test if the 1st hasn't cleaned up yet.) Looking at the code in
RemoteContext EndpointCache I don't see how this could happen though.
RemoteNamingTestCase intermittently fails on IBM JDK due to
org.jboss.remoting3.NotOpenException: Endpoint is not open
----------------------------------------------------------------------------------------------------------------------
Key: AS7-5967
URL:
https://issues.jboss.org/browse/AS7-5967
Project: Application Server 7
Issue Type: Feature Request
Components: Naming, Test Suite
Affects Versions: 7.1.3.Final (EAP), 7.2.0.Alpha1
Environment: IBM JDK 6
IBM JDK 7
Reporter: Ivo Studensky
Assignee: Ivo Studensky
RemoteNamingTestCase intermittently fails when running on IBM JDK. According to logs the
remoting channel had been closed before the endpoint tried to connect to it.
Unfortunately, when I was trying to debug this issue the tests always nicely passed.
test.log snippet:
{noformat}
13:16:31,115 DEBUG [org.xnio.nio] (Remoting
"config-based-naming-client-endpoint" read-1) Started channel thread
'Remoting "config-based-naming-client-endpoint" read-1', selector
sun.nio.ch.EPollSelectorImpl@345642e1
13:16:31,115 DEBUG [org.xnio.nio] (Remoting
"config-based-naming-client-endpoint" write-1) Started channel thread
'Remoting "config-based-naming-client-endpoint" write-1', selector
sun.nio.ch.EPollSelectorImpl@1dc68cf2
13:16:31,121 DEBUG [org.jboss.naming.remote.client.InitialContextFactory] (main)
jboss.naming.client.connect.options. has the following options
{org.xnio.Options.SASL_POLICY_NOPLAINTEXT=>false}
13:16:31,191 ERROR [org.jboss.naming.remote.protocol.v1.RemoteNamingStoreV1] (Remoting
"config-based-naming-client-endpoint" task-1) Channel end notification received,
closing channel Channel ID d1f17196 (outbound) of Remoting connection fd3dcedc to
/127.0.0.1:4447
13:16:31,204 DEBUG [org.jboss.naming.remote.client.HaRemoteNamingStore] (main) Failed to
connect to server remote://127.0.0.1:4447: org.jboss.remoting3.NotOpenException: Endpoint
is not open
at org.jboss.remoting3.EndpointImpl.resourceUntick(EndpointImpl.java:182)
at org.jboss.remoting3.EndpointImpl.doConnect(EndpointImpl.java:261)
at org.jboss.remoting3.EndpointImpl.doConnect(EndpointImpl.java:251)
at org.jboss.remoting3.EndpointImpl.connect(EndpointImpl.java:349)
at org.jboss.remoting3.EndpointImpl.connect(EndpointImpl.java:333)
at
org.jboss.naming.remote.client.EndpointCache$EndpointWrapper.connect(EndpointCache.java:105)
at
org.jboss.naming.remote.client.HaRemoteNamingStore.failOverSequence(HaRemoteNamingStore.java:179)
at
org.jboss.naming.remote.client.HaRemoteNamingStore.namingOperation(HaRemoteNamingStore.java:117)
at
org.jboss.naming.remote.client.HaRemoteNamingStore.lookup(HaRemoteNamingStore.java:223)
at org.jboss.naming.remote.client.RemoteContext.lookup(RemoteContext.java:79)
at org.jboss.naming.remote.client.RemoteContext.lookup(RemoteContext.java:83)
at javax.naming.InitialContext.lookup(InitialContext.java:422)
at
org.jboss.as.test.integration.naming.remote.simple.RemoteNamingTestCase.testRemoteLookup(RemoteNamingTestCase.java:74)
{noformat}
server.log snippet:
{noformat}
13:16:31,025 INFO [org.jboss.as.server] (management-handler-thread - 3) JBAS018559:
Deployed "test.jar"
13:16:31,163 DEBUG [org.jboss.naming.remote.server.RemoteNamingService] (Remoting
"thinkpax" task-3) Channel Opened - Channel ID 51f17196 (inbound) of Remoting
connection b9da2788 to /127.0.0.1:46866
13:16:31,176 DEBUG [org.jboss.naming.remote.server.RemoteNamingService] (Remoting
"thinkpax" task-4) Chosen version 0x01
13:16:31,189 DEBUG [org.jboss.naming.remote.server.RemoteNamingService] (Remoting
"thinkpax" read-1) Channel Channel ID 51f17196 (inbound) of Remoting connection
b9da2788 to /127.0.0.1:46866 closed.
13:16:31,193 INFO [org.jboss.as.naming] (Remoting "thinkpax" task-1)
JBAS011806: Channel end notification received, closing channel Channel ID 51f17196
(inbound) of Remoting connection b9da2788 to null
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see:
http://www.atlassian.com/software/jira