[jboss-jira] [JBoss JIRA] (AS7-5967) RemoteNamingTestCase intermittently fails on IBM JDK due to org.jboss.remoting3.NotOpenException: Endpoint is not open
Ivo Studensky (JIRA)
jira-events at lists.jboss.org
Fri Nov 23 06:35:21 EST 2012
[ https://issues.jboss.org/browse/AS7-5967?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12736639#comment-12736639 ]
Ivo Studensky commented on AS7-5967:
------------------------------------
I've added more trace logging to the EndpointCache as follows:
{code}
diff --git a/src/main/java/org/jboss/naming/remote/client/EndpointCache.java b/src/main/java/org/jboss/naming/remote/client/EndpointCache.java
index be369b7..ee3ce13 100644
--- a/src/main/java/org/jboss/naming/remote/client/EndpointCache.java
+++ b/src/main/java/org/jboss/naming/remote/client/EndpointCache.java
@@ -47,11 +47,33 @@ public class EndpointCache {
cache.putIfAbsent(endpointHash, cacheEntry);
}
cacheEntry.referenceCount.incrementAndGet();
+
+ logger.info("==============================");
+ logger.info("EndpointCache.get()");
+ logger.infof("cacheEntry.endpoint = %s", cacheEntry.endpoint);
+ logger.infof("cacheEntry.referenceCount = %s", cacheEntry.referenceCount.get());
+ logger.info("stack trace:");
+ for (StackTraceElement ste : new Throwable().getStackTrace()) {
+ logger.infof("===== \t %s", ste);
+ }
+ logger.info("==============================");
+
return cacheEntry.endpointWrapper;
}
public synchronized void release(final CacheKey endpointHash, final boolean async) {
final CacheEntry cacheEntry = cache.get(endpointHash);
+
+ logger.info("------------------------------");
+ logger.info("EndpointCache.release()");
+ logger.infof("cacheEntry.endpoint = %s", cacheEntry.endpoint);
+ logger.infof("cacheEntry.referenceCount = %s", cacheEntry.referenceCount.get());
+ logger.info("stack trace:");
+ for (StackTraceElement ste : new Throwable().getStackTrace()) {
+ logger.infof("===== \t %s", ste);
+ }
+ logger.info("------------------------------");
+
if (cacheEntry.referenceCount.decrementAndGet() == 0) {
try {
if (async) {
{code}
Here is the snippet from test log output:
{noformat}
12:22:35,244 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) ------------------------------
12:22:35,246 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) EndpointCache.release()
12:22:35,248 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) cacheEntry.endpoint = endpoint "config-based-naming-client-endpoint" <c825c546>
12:22:35,251 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) cacheEntry.referenceCount = 1
12:22:35,254 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) stack trace:
12:22:35,257 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) ===== org.jboss.naming.remote.client.EndpointCache.release(EndpointCache.java:72)
12:22:35,262 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) ===== org.jboss.naming.remote.client.EndpointCache$EndpointWrapper.closeAsync(EndpointCache.java:211)
12:22:35,265 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) ===== org.jboss.naming.remote.client.InitialContextFactory$1.close(InitialContextFactory.java:228)
12:22:35,268 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) ===== org.jboss.naming.remote.client.RemoteContext.finalize(RemoteContext.java:199)
12:22:35,271 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) ===== java.lang.J9VMInternals.runFinalize(J9VMInternals.java:455)
12:22:35,273 INFO [org.jboss.naming.remote.client.EndpointCache] (Finalizer thread) ------------------------------
{noformat}
See the attached full test log.
> 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: 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
More information about the jboss-jira
mailing list