Uploaded image for project: 'JBoss Transaction Manager'
  1. JBoss Transaction Manager
  2. JBTM-338

Slow shutdown of the transaction service

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Rejected
    • Affects Version/s: 4.3.0.BETA2
    • Fix Version/s: None
    • Component/s: JTA
    • Labels:
      None

      Description

      I'm looking in the jboss testsuite, at a group of tests that starts a custom jboss config (jacc) and spotted this failed attempt to stop the server within 45secs.

      http://hudson.qa.jboss.com/hudson/view/JBoss%20AS/job/JBoss-AS-5.0.x-TestSuite-sun15/426/console
      ...
      [server:stop] Shutting down server: jacc
      [server:stop] Shutting down server: /qa/tools/opt/jdk1.5.0_12/bin/java -cp /qa/services/hudson/hudson_workspace/workspace/JBoss-AS-5.0.x-TestSuite-sun15/trunk/build/output/jboss-5.0.0.CR1/bin/shutdown.jar:/qa/services/hudson/hudson_workspace/workspace/JBoss-AS-5.0.x-TestSuite-sun15/trunk/build/output/jboss-5.0.0.CR1/client/jbossall-client.jar:/qa/services/hudson/hudson_workspace/workspace/JBoss-AS-5.0.x-TestSuite-sun15/trunk/build/output/jboss-5.0.0.CR1/client/jboss-common.jar org.jboss.Shutdown --server jnp://10.18.96.175:1099 --shutdown
      [server:stop] shutdownTimeout will be=45
      [server:stop] Failed to shutdown server "jacc" before timeout. Destroying the process.
      ...

      By digging further in the server.log you can see that most of the shutdown sequence is completed within 1 second, but then almost a minute after the last logged message (58secs) the arjuna periodic recovery thread is still active (see below) and this causes the testsuite to kill the process.

      JBossTS seems to not shutdown properly / in-time.

      2008-03-04 04:38:43,432 DEBUG [org.jboss.resource.connectionmanager.ManagedConnectionFactoryDeployment] Stopped jboss.jca:service=ManagedConnectionFactory,name=JmsXA
      2008-03-04 04:38:43,433 DEBUG [org.jboss.jms.server.ServerPeer] Stopping jboss.messaging:service=ServerPeer
      2008-03-04 04:38:43,433 INFO [org.jboss.jms.server.ServerPeer] ServerPeer[0] is Stopping. NOTE! Stopping the server peer cleanly will NOT cause failover to occur
      2008-03-04 04:39:41,452 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Tue, 4 Mar 2008 04:39:41>
      2008-03-04 04:39:41,453 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-03-04 04:39:41,453 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-03-04 04:39:41,454 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-03-04 04:39:51,454 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Tue, 4 Mar 2008 04:39:51>
      2008-03-04 04:39:51,454 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-03-04 04:39:51,454 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-03-04 04:39:51,454 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass
      2008-03-04 04:41:51,457 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - first pass <Tue, 4 Mar 2008 04:41:51>
      2008-03-04 04:41:51,457 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule: first pass
      2008-03-04 04:41:51,458 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first pass
      2008-03-04 04:41:51,458 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
      2008-03-04 04:42:01,460 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic recovery - second pass <Tue, 4 Mar 2008 04:42:01>
      2008-03-04 04:42:01,460 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] AtomicActionRecoveryModule: Second pass
      2008-03-04 04:42:01,460 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N] [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second pass
      2008-03-04 04:42:01,460 DEBUG [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second pass

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                adinn Andrew Dinn
                Reporter:
                dimitris Dimitrios Andreadis
              • Votes:
                0 Vote for this issue
                Watchers:
                0 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: