[
https://issues.jboss.org/browse/AS7-5967?page=com.atlassian.jira.plugin.s...
]
Ivo Studensky commented on AS7-5967:
------------------------------------
IBM JDK seems to be too fast. The culprit of this issue is that IBM JDK sometimes
finalizes the InitialContext created by getRemoteContext() method before the lookup()
method finishes. See the following log snippet. The RemoteContext is finalized by
J9VMInternals.runFinalize and then lookup() method fails.
{noformat}
16:21:13,521 TRACE [org.jboss.remoting.resource] (Finalizer thread) my own stack trace
from AbstractHandleableCloseable#closeAsync at ENTRY:
16:21:13,524 TRACE [org.jboss.remoting.resource] (Finalizer thread)
org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync(AbstractHandleableCloseable.java:350)
16:21:13,529 TRACE [org.jboss.remoting.resource] (Finalizer thread)
org.jboss.remoting3.EndpointImpl.closeAction(EndpointImpl.java:208)
16:21:13,535 TRACE [org.jboss.remoting.resource] (Finalizer thread)
org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync(AbstractHandleableCloseable.java:369)
16:21:13,539 TRACE [org.jboss.remoting.resource] (Finalizer thread)
org.jboss.naming.remote.client.EndpointCache.release(EndpointCache.java:58)
16:21:13,543 TRACE [org.jboss.remoting.resource] (Finalizer thread)
org.jboss.naming.remote.client.EndpointCache$EndpointWrapper.closeAsync(EndpointCache.java:189)
16:21:13,545 TRACE [org.jboss.remoting.resource] (Finalizer thread)
org.jboss.naming.remote.client.InitialContextFactory$1.close(InitialContextFactory.java:228)
16:21:13,555 TRACE [org.jboss.remoting.resource] (Finalizer thread)
org.jboss.naming.remote.client.RemoteContext.finalize(RemoteContext.java:199)
16:21:13,558 TRACE [org.jboss.remoting.resource] (Finalizer thread)
java.lang.J9VMInternals.runFinalize(J9VMInternals.java:455)
16:21:13,562 TRACE [org.jboss.remoting.resource] (Finalizer thread) Closing Remoting
remote connection provider 50f78597 for endpoint
"config-based-naming-client-endpoint" <e6872e7> asynchronously
16:21:13,570 TRACE [org.jboss.remoting.endpoint] (Finalizer thread) Phase 1 shutdown count
00000001 of endpoint "config-based-naming-client-endpoint" <e6872e7>
(closed a cancelled connection)
16:21:13,571 TRACE [org.xnio.nio.selector] (Remoting
"config-based-naming-client-endpoint" read-1) Beginning select on
sun.nio.ch.EPollSelectorImpl@3e388ef1
16:21:13,574 TRACE [org.xnio.nio.selector] (Remoting
"config-based-naming-client-endpoint" read-1) Selected on
sun.nio.ch.EPollSelectorImpl@3e388ef1
16:21:13,576 TRACE [org.xnio.nio.selector] (Remoting
"config-based-naming-client-endpoint" read-1) Beginning select on
sun.nio.ch.EPollSelectorImpl@3e388ef1
16:21:13,575 DEBUG [org.jboss.naming.remote.client.HaRemoteNamingStore] (main) Failed to
connect to server remote://127.0.0.1:4447: java.lang.RuntimeException: Operation failed
with status CANCELLED
at org.jboss.naming.remote.protocol.IoFutureHelper.get(IoFutureHelper.java:89)
at
org.jboss.naming.remote.client.HaRemoteNamingStore.failOverSequence(HaRemoteNamingStore.java:180)
at
org.jboss.naming.remote.client.HaRemoteNamingStore.namingStore(HaRemoteNamingStore.java:131)
at
org.jboss.naming.remote.client.HaRemoteNamingStore.namingOperation(HaRemoteNamingStore.java:112)
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:77)
{noformat}
The current test method which does not work on IBM JDK is as follows:
{code}
@Test public void testRemoteLookup() throws Exception {
assertEquals("TestValue", getRemoteContext().lookup("test"));
}
{code}
And this is a slightly modified test method which works on IBM JDK nicely (it holds an
explicit reference to the InitialContext):
{code}
@Test public void testRemoteLookup() throws Exception {
Context context = null;
try {
context = getRemoteContext();
assertEquals("TestValue", context.lookup("test"));
} finally {
if (context != null)
context.close();
}
}
{code}
Note that the issue disappears when running with any Byteman's script, i.e. it is not
possible to debug it with Byteman. That's the reason why I had to modify the remoting
sources to print out a stack trace on closeAsync method entry.
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: Test Suite
Affects Versions: 7.1.3.Final (EAP)
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