[jboss-jira] [JBoss JIRA] (AS7-5967) RemoteNamingTestCase intermittently fails on IBM JDK due to org.jboss.remoting3.NotOpenException: Endpoint is not open

[Brian Stansberry (JIRA)]

    [ https://issues.jboss.org/browse/AS7-5967?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12737293#comment-12737293 ] 

Brian Stansberry commented on AS7-5967:
---------------------------------------

Luckily in this case the timing issues are quite clear. There are 3 basic events -- construct, lookup, finalize -- with the first two done on one thread and the 3rd on another. Logically, the 3rd has to follow the 1st, and does in the logs. The logs show the 3rd happening in the middle of execution of the 2nd. We know that reported timing is essentially accurate, because the 3rd is producing side effects (closing the endpoint) that result in failure of the 2nd.

Once the constructor executes there is a reference chain leading back to a variable on the stack that should be sufficient to keep the RemoteContext from being gc'd.
                
> 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 (build 20110203_074623)
> IBM JDK 7 (build 20120809_118929)
>            Reporter: Ivo Studensky
>            Assignee: Ivo Studensky
>         Attachments: endpoint_is_not_open_2012-11-26.xml, failed_with_status_cancelled_2012-11-26.xml, test_output_with_trace_logging_in_EndpointCache.xml
>
>
> 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 at 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 at 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