5 Replies Latest reply on Nov 13, 2013 12:23 PM by Justin Bertram

    JMS  messageProducer.send(objectMessage) hangs after 216 sucessfull sends??

    Joseph Fouts Novice

      I have a process that is trying to send 500 messages to a JMS message queue.

       

      This process consistantly hangs when attempting to send the 217 message.

       

      It always hangs on the following statement:

       

      messageProducer.send(objectMessage);

       

      I have been looking at every possible setting and I can't figure out why this is hanging.

       

      Any ideas?

       

      Here is what my server logs looks like:

       

      09:29:30,110 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (EJB default - 1) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@78630ffa, connection : org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@3b9b0e0d, key: org.jboss.as.connector.deployers.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@12876401

      09:29:30,110 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [Connection] prepareStatement(Select KEY0 From JDBRGAC WHERE KEY0 = 'QA1          RGF150624709:29:1700217' FOR READ ONLY)

      09:29:30,111 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [Statement] setQueryTimeout(60)

      09:29:30,111 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [PreparedStatement] executeQuery()

      09:29:30,114 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [ResultSet] next()

      09:29:30,114 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [Statement] close()

      09:29:30,114 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [Connection] isClosed()

      09:29:30,114 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [Connection] close()

      09:29:30,114 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) connectionClosed called mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@2cec0130

      09:29:30,114 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (EJB default - 1) unregistering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@78630ffa, connection: org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@3b9b0e0d, key: org.jboss.as.connector.deployers.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@12876401

      09:29:30,115 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) unregisterConnection: 0 handles left

      09:29:30,115 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) isManagedConnectionFree=false mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@2cec0130

      09:29:30,115 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [Connection] isClosed()

      09:29:30,115 TRACE [com.lidp.enterprise.persistence.entities.dbutil.ADBRGAC_DBUtil] (EJB default - 1) [2013-11-12][09:29:17][1506247][SEGRMA  ][ADBRGAC_DBUtil           ][insert                        ]

      09:29:30,115 TRACE [com.lidp.enterprise.persistence.entities.dbutil.ADBRGAC_DBUtil] (EJB default - 1) insert_LoadDBStatement

      09:29:30,115 TRACE [com.lidp.enterprise.persistence.entities.dbutil.ADBRGAC_DBUtil] (EJB default - 1) [2013-11-12][09:29:17][1506247][SEGRMA  ][ADBRGAC_DBUtil           ][setOverrideTableName          ]

      09:29:30,115 TRACE [com.lidp.enterprise.persistence.entities.dbutil.ADBRGAC_DBUtil] (EJB default - 1) ajSwapFirstChar

      09:29:30,115 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 1) Subject: null

      09:29:30,115 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 1) getManagedConnection interleaving=false , tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,116 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 1) Previous connection tracked by transaction=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7aa9f84a[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@2cec0130 connection handles=0 lastUse=1384356557257 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3a420d5a pool internal context=SemaphoreArrayListManagedConnectionPool@2a93424f[pool=db2DataSource] xaResource=LocalXAResourceImpl@467aad97[connectionListener=7aa9f84a connectionManager=78630ffa warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-1a751229:52839abd:f, node_name=1, branch_uid=0:ffff7f000001:-1a751229:52839abd:11, subordinatenodename=null, eis_name=unknown eis name >] txSync=TxSync647719910{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,116 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) Pre-enlist: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7aa9f84a[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@2cec0130 connection handles=0 lastUse=1384356557257 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3a420d5a pool internal context=SemaphoreArrayListManagedConnectionPool@2a93424f[pool=db2DataSource] xaResource=LocalXAResourceImpl@467aad97[connectionListener=7aa9f84a connectionManager=78630ffa warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-1a751229:52839abd:f, node_name=1, branch_uid=0:ffff7f000001:-1a751229:52839abd:11, subordinatenodename=null, eis_name=unknown eis name >] txSync=TxSync647719910{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,116 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) Get synchronizer org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7aa9f84a[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@2cec0130 connection handles=0 lastUse=1384356557257 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3a420d5a pool internal context=SemaphoreArrayListManagedConnectionPool@2a93424f[pool=db2DataSource] xaResource=LocalXAResourceImpl@467aad97[connectionListener=7aa9f84a connectionManager=78630ffa warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-1a751229:52839abd:f, node_name=1, branch_uid=0:ffff7f000001:-1a751229:52839abd:11, subordinatenodename=null, eis_name=unknown eis name >] txSync=TxSync647719910{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,116 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) Check enlisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@7aa9f84a[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@2cec0130 connection handles=0 lastUse=1384356557257 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@3a420d5a pool internal context=SemaphoreArrayListManagedConnectionPool@2a93424f[pool=db2DataSource] xaResource=LocalXAResourceImpl@467aad97[connectionListener=7aa9f84a connectionManager=78630ffa warned=false currentXid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff7f000001:-1a751229:52839abd:f, node_name=1, branch_uid=0:ffff7f000001:-1a751229:52839abd:11, subordinatenodename=null, eis_name=unknown eis name >] txSync=TxSync647719910{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,116 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (EJB default - 1) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@78630ffa, connection : org.jboss.jca.adapters.jdbc.jdk6.WrappedConnectionJDK6@8a07b6c, key: org.jboss.as.connector.deployers.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@12876401

      09:29:30,116 DEBUG [jboss.jdbc.spy] (EJB default - 1) java:/db2DataSource [Connection] prepareStatement(INSERT into JDBRGAC  ( KEY0, KEY1, COMPANY_CODE, POLICY_NUMBER, RECORD_ID, TASK_NUMBER, SYSTEM_TIME, SEQUENCE_COUNT, AK1_COMPANY_CODE, AK1_REPORT_ID, PRINT_STATUS, AK1_VARIABLE_KEY, PREV_JRNL_DATE, PREV_JRNL_DUP, CURRENT_PROC_DATE, CYCLE_DUP_NO, DPDSK, AC_TIME, AC_DATE, TRANSACTION_CODE, COMP_CD, POL_NO, COMMENTS, WORD_PROC_SW, DEST_TYPE, FAX_NUMBER, BEEPER_NUMBER, MOBILE_NUMBER, EMAIL_ADDRESS, ROUTE_DESK, VDO_RULE, VARIABLE_DATA_OBJECT ) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?))

      09:29:30,116 TRACE [com.lidp.enterprise.persistence.entities.dbutil.ADBRGAC_DBUtil] (EJB default - 1) insert_LoadDB

      09:29:30,117 TRACE [com.lidp.enterprise.util.QMaint_Util] (EJB default - 1) [2013-11-12][09:29:17][1506247][SEGRMA  ][QMaint_Util              ][writeMessage                  ]

      09:29:30,117 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 1) Subject: null

      09:29:30,117 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (EJB default - 1) getManagedConnection interleaving=false , tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,117 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (EJB default - 1) Previous connection tracked by transaction=org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@5ce684c5[state=NORMAL managed connection=org.hornetq.ra.HornetQRAManagedConnection@2216d129 connection handles=0 lastUse=1384356565160 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@7fdec3b pool internal context=SemaphoreArrayListManagedConnectionPool@77594090[pool=HornetQConnectionDefinition] xaResource=XAResourceWrapperImpl@2fa01996[xaResource=org.hornetq.ra.HornetQRAXAResource@37efdf47 pad=false overrideRmValue=false productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] txSync=TxSync1697368833{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,117 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) Pre-enlist: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@5ce684c5[state=NORMAL managed connection=org.hornetq.ra.HornetQRAManagedConnection@2216d129 connection handles=0 lastUse=1384356565160 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@7fdec3b pool internal context=SemaphoreArrayListManagedConnectionPool@77594090[pool=HornetQConnectionDefinition] xaResource=XAResourceWrapperImpl@2fa01996[xaResource=org.hornetq.ra.HornetQRAXAResource@37efdf47 pad=false overrideRmValue=false productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] txSync=TxSync1697368833{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,117 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) Get synchronizer org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@5ce684c5[state=NORMAL managed connection=org.hornetq.ra.HornetQRAManagedConnection@2216d129 connection handles=0 lastUse=1384356565160 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@7fdec3b pool internal context=SemaphoreArrayListManagedConnectionPool@77594090[pool=HornetQConnectionDefinition] xaResource=XAResourceWrapperImpl@2fa01996[xaResource=org.hornetq.ra.HornetQRAXAResource@37efdf47 pad=false overrideRmValue=false productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] txSync=TxSync1697368833{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,117 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (EJB default - 1) Check enlisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@5ce684c5[state=NORMAL managed connection=org.hornetq.ra.HornetQRAManagedConnection@2216d129 connection handles=0 lastUse=1384356565160 trackByTx=true pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@7fdec3b pool internal context=SemaphoreArrayListManagedConnectionPool@77594090[pool=HornetQConnectionDefinition] xaResource=XAResourceWrapperImpl@2fa01996[xaResource=org.hornetq.ra.HornetQRAXAResource@37efdf47 pad=false overrideRmValue=false productName=HornetQ productVersion=2.0 jndiName=java:/JmsXA] txSync=TxSync1697368833{tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING > wasTrackByTx=true enlisted=true}] threadTx=TransactionImple < ac, BasicAction: 0:ffff7f000001:-1a751229:52839abd:f status: ActionStatus.RUNNING >

      09:29:30,117 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (EJB default - 1) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@1bb94fcf, connection : org.hornetq.ra.HornetQRASession@68752860, key: org.jboss.as.connector.deployers.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@12876401

      ---->   09:29:30,118 TRACE [com.lidp.enterprise.util.QMaint_Util] (EJB default - 1) Writing process message.

       

      09:31:21,669 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) RecoverySecurityDomain was empty

      09:31:21,670 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Subject for recovery was null

      09:33:31,673 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) RecoverySecurityDomain was empty

      09:33:31,673 DEBUG [org.jboss.jca.core.tx.jbossts.XAResourceRecoveryImpl] (Periodic Recovery) Subject for recovery was null