[jboss-dev] Delayed Shutdown

[Dimitris Andreadis]

The next run went through, so we don't know what caused it.
http://hudson.qa.jboss.com/hudson/view/JBoss%20AS/job/JBoss-AS-5.0.x-TestSuite-sun15/650/

Brian Stansberry wrote:
> Ron,
> 
> I'd better defer this one to you for an opinion. :)
> 
> I don't really see how the JBAS-5590 change would cause this, but that 
> was a minor issue affecting just one unit test of an edge-case, so for 
> now I'll revert that and re-open the JIRA. Once we know it's safe to 
> proceed I can restore the fix.
> 
> Here's what I've found:
> 
> The SocketServerInvoker that might be taking a long time to finalize is 
> the one for the EJB3 connector:
> 
> 2008-06-11 05:31:12,707 DEBUG 
> [org.jboss.deployers.plugins.deployers.DeployersImpl] (JBoss Shutdown 
> Hook) Fully Undeployed 
> vfsfile:/qa/services/hudson/hudson_workspace/workspace/JBoss-AS-5.0.x-TestSuite-sun15/trunk/build/output/jboss-5.0.0.CR1/server/all/conf/jboss-service.xml 
> 
> 2008-06-11 05:31:54,744 DEBUG [org.jboss.remoting.ServerInvoker] 
> (Finalizer) SocketServerInvoker[10.18.6.175:3873] stopped
> 
> Looking earlier in the log, I see that SocketServerInvoker was already 
> stopped as part of the undeploy of the connector:
> 
> 2008-06-11 05:31:02,486 DEBUG [org.jboss.system.ServiceController] 
> (JBoss Shutdown Hook) stopping service: 
> jboss.remoting:type=Connector,name=DefaultEjb3Connector,handler=ejb3
> 2008-06-11 05:31:02,486 DEBUG 
> [org.jboss.remoting.transport.socket.SocketServerInvoker] (JBoss 
> Shutdown Hook) SocketServerInvoker[10.18.6.175:3873] stopped threads in 
> clientpool
> 2008-06-11 05:31:02,486 DEBUG 
> [org.jboss.remoting.transport.socket.SocketServerInvoker] 
> (ServerSocketRefresh) ServerSocketRefresh shutting down
> 2008-06-11 05:31:02,487 DEBUG 
> [org.jboss.remoting.transport.socket.SocketServerInvoker] (JBoss 
> Shutdown Hook) SocketServerInvoker[10.18.6.175:3873] stopped threads in 
> threadpool
> 2008-06-11 05:31:02,487 DEBUG 
> [org.jboss.remoting.transport.socket.SocketServerInvoker] (JBoss 
> Shutdown Hook) SocketServerInvoker[10.18.6.175:3873] exiting
> 2008-06-11 05:31:02,487 DEBUG [org.jboss.remoting.ServerInvoker] (JBoss 
> Shutdown Hook) SocketServerInvoker[10.18.6.175:3873] stopped
> 2008-06-11 05:31:02,487 DEBUG [org.jboss.system.ServiceController] 
> (JBoss Shutdown Hook) destroying service: 
> jboss.remoting:type=Connector,name=DefaultEjb3Connector,handler=ejb3
> 2008-06-11 05:31:02,487 DEBUG [org.jboss.system.ServiceController] 
> (JBoss Shutdown Hook) removing service: 
> jboss.remoting:type=Connector,name=DefaultEjb3Connector,handler=ejb3
> 2008-06-11 05:31:02,487 DEBUG [org.jboss.system.ServiceCreator] (JBoss 
> Shutdown Hook) Removing mbean from server: 
> jboss.remoting:type=Connector,name=DefaultEjb3Connector,handler=ejb3
> 2008-06-11 05:31:02,490 DEBUG 
> [org.jboss.deployers.structure.spi.helpers.AbstractDeploymentContext] 
> (JBoss Shutdown Hook) Removed component 
> jboss.remoting:handler=ejb3,name=DefaultEjb3Connector,type=Connector 
> from 
> vfsfile:/qa/services/hudson/hudson_workspace/workspace/JBoss-AS-5.0.x-TestSuite-sun15/trunk/build/output/jboss-5.0.0.CR1/server/all/deploy/ejb3-connectors-service.xml 
> 
> 
> The finalize() method on SocketServerInvoker calls stop() again; hence 
> the second logging.  Looking at the stop() code I don't see anything 
> that should take a long time; the first call to stop() should have 
> already called destroy() on any ServerInvokerCallbackHandler, and once 
> that's done, doing it again should be very fast, just a couple of null 
> checks.
> 
> It's quite possible this is completely unrelated to remoting; i.e. 
> something else is going on with the Finalizer thread and it's just our 
> bad luck that remoting happened to log something and focus attention on 
> us. :-)
> 
> - Brian
> 
> Brian Stansberry wrote:
>> I'll have a look. I for sure I didn't see that effect when I tested 
>> that change.
>>
>> Dimitris Andreadis wrote:
>>> Hm, probably related to this:
>>> http://jira.jboss.com/jira/browse/JBAS-5590?page=comments
>>>
>>> Dimitris Andreadis wrote:
>>>> The AS testsuite fails because of a delayed shutdown of the all config:
>>>> http://hudson.qa.jboss.com/hudson/view/JBoss%20AS/job/JBoss-AS-5.0.x-TestSuite-sun15/649/artifact/trunk/build/output/jboss-5.0.0.CR1/server/all/log/ 
>>>>
>>>>
>>>> The last entry in the log is this weird ServerInvoker finalizer 
>>>> thread the seems to be holding the server for more than 42 seconds 
>>>> after the previous log message:
>>>>
>>>> Any idea where is this coming from?
>>>>
>>>> 2008-06-11 05:31:12,707 DEBUG 
>>>> [org.jboss.deployers.plugins.deployers.DeployersImpl] (JBoss 
>>>> Shutdown Hook) Fully Undeployed 
>>>> vfsfile:/qa/services/hudson/hudson_workspace/workspace/JBoss-AS-5.0.x-TestSuite-sun15/trunk/build/output/jboss-5.0.0.CR1/server/all/conf/jboss-service.xml 
>>>>
>>>> 2008-06-11 05:31:54,744 DEBUG [org.jboss.remoting.ServerInvoker] 
>>>> (Finalizer) SocketServerInvoker[10.18.6.175:3873] stopped
>>>>
>>>> _______________________________________________
>>>> jboss-development mailing list
>>>> jboss-development at lists.jboss.org
>>>> https://lists.jboss.org/mailman/listinfo/jboss-development
>>
>