Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-5656

FatalError on Transaction Expired Entry Monitor during server shutdown

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Won't Do
    • Icon: Minor Minor
    • None
    • 7.1.0.DR2
    • IIOP, Transactions
    • None
    • Hide

      I do not have any test as reproducer. I can see it when running multiple JTS transaction crashrecovery testsuite when jdbc object store is used. For example this test job shows this any time when it's run. But the failure could be observe in different testcases which are run.

      https://eap-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/job/jbossts-crashrec-testsuite-merge-request-verifier/40/LABEL=RHEL7,OBJECT_STORE_TYPE=jdbcstore%20postgresql93,jdk=openjdk-1.8/console

      Show
      I do not have any test as reproducer. I can see it when running multiple JTS transaction crashrecovery testsuite when jdbc object store is used. For example this test job shows this any time when it's run. But the failure could be observe in different testcases which are run. https://eap-qe-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/job/jbossts-crashrec-testsuite-merge-request-verifier/40/LABEL=RHEL7,OBJECT_STORE_TYPE=jdbcstore%20postgresql93,jdk=openjdk-1.8/console

      I do experience intermittent errors being shown in server log during server shutdown. It happens time to time for server configured to use JTS transaction that Transaction Expired Entry Monitor shows FatalError during container shutdown.

      I do experience this failure when jdbc object store is used.

      The shutdown log looks

      2016-08-16 07:07:46,900 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0028: Stopped deployment wmq.jmsra.rar (runtime-name: wmq.jmsra.rar) in 132ms
2016-08-16 07:07:46,914 INFO  [org.wildfly.extension.messaging-activemq] (MSC service thread 1-2) WFLYMSGAMQ0006: Unbound messaging object to jndi name java:jboss/DefaultJMSConnectionFactory
2016-08-16 07:07:46,914 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-2) WFLYJCA0010: Unbound data source [java:jboss/datasources/ExampleDS]
2016-08-16 07:07:46,915 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-4) WFLYJCA0011: Unbound JCA ConnectionFactory [java:/JmsXA]
2016-08-16 07:07:46,921 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) WFLYJCA0019: Stopped Driver service with driver-name = h2
2016-08-16 07:07:46,924 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-4) WFLYSRV0028: Stopped deployment crashrecovery-jms-stateless-cmt.jar (runtime-name: crashrecovery-jms-stateless-cmt.jar) in 156ms
2016-08-16 07:07:46,947 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 16) WFLYCLINF0003: Stopped client-mappings cache from ejb container
2016-08-16 07:07:46,952 TRACE [com.arjuna.ats.arjuna] (Transaction Expired Entry Monitor) InputObjectState::InputObjectState(0:ffff7f000001:55f44a88:57b2ec0b:8, Recovery/FactoryContact)
2016-08-16 07:07:46,959 INFO  [org.apache.activemq.artemis.ra] (ServerService Thread Pool -- 32) AMQ151003: resource adaptor stopped
2016-08-16 07:07:46,962 TRACE [com.arjuna.orbportability] (MSC service thread 1-4) ORB::shutdown ()
2016-08-16 07:07:46,962 TRACE [com.arjuna.orbportability] (MSC service thread 1-4) OA::destroyRootPOA ()
2016-08-16 07:07:46,962 TRACE [com.arjuna.orbportability] (MSC service thread 1-4) RootOA::shutdownObject (Servant)
2016-08-16 07:07:46,962 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-4) ARJUNA032018: Destroying TransactionManagerService
2016-08-16 07:07:46,963 INFO  [com.arjuna.ats.jbossatx] (MSC service thread 1-4) ARJUNA032014: Stopping transaction recovery manager
2016-08-16 07:07:47,000 FATAL [com.arjuna.ats.jts] (Transaction Expired Entry Monitor) ARJUNA022006: The ORB has not been initialized yet
2016-08-16 07:07:47,001 ERROR [stderr] (Transaction Expired Entry Monitor) Exception in thread "Transaction Expired Entry Monitor" com.arjuna.ats.arjuna.exceptions.FatalError
2016-08-16 07:07:47,001 ERROR [stderr] (Transaction Expired Entry Monitor) 	at com.arjuna.ats.internal.jts.ORBManager.getORB(ORBManager.java:56)
2016-08-16 07:07:47,001 ERROR [stderr] (Transaction Expired Entry Monitor) 	at com.arjuna.ats.internal.jts.recovery.contact.FactoryContactItem.restore_state(FactoryContactItem.java:264)
2016-08-16 07:07:47,001 ERROR [stderr] (Transaction Expired Entry Monitor) 	at com.arjuna.ats.internal.jts.recovery.contact.FactoryContactItem.restoreMe(FactoryContactItem.java:320)
2016-08-16 07:07:47,001 ERROR [stderr] (Transaction Expired Entry Monitor) 	at com.arjuna.ats.internal.jts.recovery.contact.FactoryContactItem.recreate(FactoryContactItem.java:100)
2016-08-16 07:07:47,001 ERROR [stderr] (Transaction Expired Entry Monitor) 	at com.arjuna.ats.internal.jts.recovery.contact.ExpiredContactScanner.scan(ExpiredContactScanner.java:99)
2016-08-16 07:07:47,001 ERROR [stderr] (Transaction Expired Entry Monitor) 	at com.arjuna.ats.internal.arjuna.recovery.ExpiredEntryMonitor.run(ExpiredEntryMonitor.java:171)
2016-08-16 07:07:47,001 DEBUG [com.arjuna.ats.arjuna] (Listener:4712) Recovery listener existing com.arjuna.ats.internal.arjuna.recovery.WorkerService
2016-08-16 07:07:47,002 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: Mode <== TERMINATED
2016-08-16 07:07:47,002 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: shutdown waiting for scan to end
2016-08-16 07:07:47,002 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: scan TERMINATED at phase 1
2016-08-16 07:07:47,002 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE
2016-08-16 07:07:47,002 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread exiting
2016-08-16 07:07:47,002 DEBUG [com.arjuna.ats.arjuna] (MSC service thread 1-4) PeriodicRecovery: shutdown scan wait complete
2016-08-16 07:07:47,003 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) WFLYJCA0010: Unbound data source [java:jboss/datasources/jdbc-store]
2016-08-16 07:07:47,006 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-4) WFLYJCA0019: Stopped Driver service with driver-name = module_postgresql-9.4.1207.jar
2016-08-16 07:07:47,012 INFO  [org.apache.activemq.artemis.core.server] (ServerService Thread Pool -- 32) AMQ221002: Apache ActiveMQ Artemis Message Broker version 1.1.0.SP16-redhat-1 [023d1e88-638c-11e6-927a-a180c25082cf] stopped
2016-08-16 07:07:47,012 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0008: Undertow HTTP listener default suspending
2016-08-16 07:07:47,013 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0007: Undertow HTTP listener default stopped, was bound to 127.0.0.1:8080
2016-08-16 07:07:47,013 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0004: Undertow 1.3.21.Final-redhat-1 stopping
2016-08-16 07:07:47,018 INFO  [org.jboss.as] (MSC service thread 1-1) WFLYSRV0050: JBoss EAP 7.0.0.GA (WildFly Core 2.1.2.Final-redhat-1) stopped in 250ms

              tadamski@redhat.com Tomasz Adamski
              ochaloup@redhat.com Ondrej Chaloupka (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: