So, basically the DelegatingSession is being released before the call to close is finished.

That's weird I know... but we have no control over that.

This was happening on MultiThreadRandomReattachTestBase::testB.

The s.close() here was not on finalize but it was the lass call before s went out of scope.


I said it was on finalize initially as I changed this locally on my computer but reverted it later. I saw the same behaviour with logs and everything on both scenarios.

for (int i = 0; i < numSessions; i++)
 {
 SimpleString subName = new SimpleString(threadNum + "sub" + i);

 s.deleteQueue(subName);
 }

 s.close();

 long end = System.currentTimeMillis();

 log.info("duration " + (end - start));

 }

I was also very confused... I added extra logs...


The close happens in two steps... the first one will set in close.. if there is an exception, cleanup will be called and at that time the closed is set to true.

Perhaps the closed couldn't be set?

I added logging on that, and I couldn't find any exceptions.. but maybe I missed it.

On the case of the exceptions during close.. the code I added into DelegatingSession would be enough to fix the issue.

I don't think it's worth investing more time on it. The issue is not happening any more after your latest fixes. (I have done several tests on it) And even if it does.. (any exception aborting close), the code on delegatingSession will avoid the "didn't close session" exceptions for the sessions the user closed. (which would only happen rarely during a reattach while calling session.close(); i.e... never!)

Actually.. I could just replicate the issue on my 32 bits laptop....


I was running on my laptop (64 bits), on my workstation (8 core, 64 bits).. and I could easily replicate it on my old laptop (32 bits).


First, I added the following hacks:

On ClientSessionImpl, I exposed inClose.. and I set the thread that is calling close.''

 private volatile Thread inCloseThread;

 public boolean isClosing()
 {
 return this.inClose;
 }

 public void debug()
 {
 if (inCloseThread != null)
 {
 log.warn("Thread " + inCloseThread + " is at this place");
 StackTraceElement[] stack = inCloseThread.getStackTrace();

 for (StackTraceElement el : stack)
 {
 log.warn(el.toString());
 }
 }
 }

 public void close() throws HornetQException
 {
 if (closed)
 {
 return;
 }

 this.inCloseThread = Thread.currentThread();

 try
 {

 try
 {
 producerCreditManager.close();

 closeChildren();

 inClose = true;

 channel.sendBlocking(new SessionCloseMessage());
 }
 catch (Throwable e)
 {
 // Session close should always return without exception

 // Note - we only log at trace
 ClientSessionImpl.log.warn("Failed to close session", e);
 }

 try
 {
 doCleanup();
 }
 catch (Exception e)
 {
 log.warn("Couldn't complete cleanup", e);
 }

 }
 finally
 {
 this.inCloseThread = null;
 }
 }

@Override
 protected void finalize() throws Throwable
 {
 if (!session.isClosed())
 {
 DelegatingSession.log.warn("I'm closing a core ClientSession you left open. Please make sure you close all ClientSessions explicitly " + "before letting them go out of scope! " +
 System.identityHashCode(this));

 DelegatingSession.log.warn("The ClientSession you didn't close was created here:", creationStack);

 log.warn("finalize block being called here:", new Exception("trace"));

 if (((ClientSessionImpl)session).isClosing())
 {
 ((ClientSessionImpl)session).debug();
 }

 close();
 }

 super.finalize();
 }

[Finalizer] 21:59:00,158 WARNING [org.hornetq.core.client.impl.DelegatingSession] The ClientSession you didn't close was created here:
java.lang.Exception
 at org.hornetq.core.client.impl.DelegatingSession.<init>(DelegatingSession.java:95)
 at org.hornetq.core.client.impl.FailoverManagerImpl.createSession(FailoverManagerImpl.java:433)
 at org.hornetq.core.client.impl.ClientSessionFactoryImpl.createSessionInternal(ClientSessionFactoryImpl.java:1120)
 at org.hornetq.core.client.impl.ClientSessionFactoryImpl.createSession(ClientSessionFactoryImpl.java:885)
 at org.hornetq.tests.integration.cluster.reattach.MultiThreadRandomReattachTestBase.doTestB(MultiThreadRandomReattachTestBase.java:426)
 at org.hornetq.tests.integration.cluster.reattach.MultiThreadRandomReattachTestBase$2.run(MultiThreadRandomReattachTestBase.java:93)
 at org.hornetq.tests.integration.cluster.reattach.MultiThreadReattachSupport$1Runner.run(MultiThreadReattachSupport.java:129)
[Finalizer] 21:59:00,181 WARNING [org.hornetq.core.client.impl.DelegatingSession] finalize block being called here:
java.lang.Exception: trace
 at org.hornetq.core.client.impl.DelegatingSession.finalize(DelegatingSession.java:78)
 at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
 at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
 at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
 at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)
[Finalizer] 21:59:00,182 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] Thread Thread[Thread-251,5,main] is at this place
[Finalizer] 21:59:00,190 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.FailoverManagerImpl.removeSession(FailoverManagerImpl.java:488)
[Finalizer] 21:59:00,190 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.ClientSessionImpl.doCleanup(ClientSessionImpl.java:1642)
[Finalizer] 21:59:00,191 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.ClientSessionImpl.close(ClientSessionImpl.java:838)
[Finalizer] 21:59:00,191 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.DelegatingSession.close(DelegatingSession.java:145)
[Finalizer] 21:59:00,192 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.tests.integration.cluster.reattach.MultiThreadRandomReattachTestBase.doTestB(MultiThreadRandomReattachTestBase.java:465)
[Finalizer] 21:59:00,192 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.tests.integration.cluster.reattach.MultiThreadRandomReattachTestBase$2.run(MultiThreadRandomReattachTestBase.java:93)
[Finalizer] 21:59:00,192 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.tests.integration.cluster.reattach.MultiThreadReattachSupport$1Runner.run(MultiThreadReattachSupport.java:129)
[

[Finalizer] 21:59:00,182 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] Thread Thread[Thread-251,5,main] is at this place
[Finalizer] 21:59:00,190 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.FailoverManagerImpl.removeSession(FailoverManagerImpl.java:488)
[Finalizer] 21:59:00,190 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.ClientSessionImpl.doCleanup(ClientSessionImpl.java:1642)
[Finalizer] 21:59:00,191 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.ClientSessionImpl.close(ClientSessionImpl.java:838)
[Finalizer] 21:59:00,191 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.core.client.impl.DelegatingSession.close(DelegatingSession.java:145)
[Finalizer] 21:59:00,192 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.tests.integration.cluster.reattach.MultiThreadRandomReattachTestBase.doTestB(MultiThreadRandomReattachTestBase.java:465)
[Finalizer] 21:59:00,192 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.tests.integration.cluster.reattach.MultiThreadRandomReattachTestBase$2.run(MultiThreadRandomReattachTestBase.java:93)
[Finalizer] 21:59:00,192 WARNING [org.hornetq.core.client.impl.ClientSessionImpl] org.hornetq.tests.integration.cluster.reattach.MultiThreadReattachSupport$1Runner.run(MultiThreadReattachSupport.java:129)
[