DefaultMessageListenerContainer and Websphere default JMS provider (SIB)

**gadams00** · Jan 17th, 2012, 11:32 AM

I'm working on an application that uses Spring DefaultMessageListenerContainer on Websphere using the default message provider (service integration bus). The behavior I'm seeing is that when not using a transactionManager on the DefaultMessageListenerContainer beans, hundreds of JMS connections are created and closed when the application is sitting idle (the DMLCs are not receiving any messages). When a transactionManager is specified, this does not happen, but we don't use an XA datasource, so we get errors related to that when a transactionManager is specifed when processing messages. We'd rather not use an XA datasource, but I'm concerned over the resource thrashing present when not using a transactionManager. Is there something I'm not configuring correctly that would cause this thrashing on JMS connections?

Here's the relevant portion of the spring configuration:

Code:

<bean id="messagingTaskExecutor"
		class="org.springframework.scheduling.commonj.WorkManagerTaskExecutor">
		<property name="workManagerName" value="com/landacorp/jms/workmanager" />
    	<property name="resourceRef" value="true" />
	</bean>

<jee:jndi-lookup id="careRadiusConnectionFactory"
		jndi-name="java:comp/env/com/landacorp/jms/CareRadiusConnectionFactory" />

<jee:jndi-lookup id="careRadiusReportRequestQueue"
 		jndi-name="java:comp/env/com/landacorp/jms/dest/CareRadiusReportRequestQueue" />
	

<bean id="crystalAgentContainerNormalPriority" class="org.springframework.jms.listener.DefaultMessageListenerContainer">
		<property name="taskExecutor" ref="messagingTaskExecutor" />
		<property name="sessionTransacted" value="true" />
		<property name="connectionFactory" ref="careRadiusConnectionFactory" />
		<property name="destination" ref="careRadiusReportRequestQueue" />
		<property name="messageListener" ref="crystalAgent" />
		<property name="concurrentConsumers" value="3" />
		<property name="messageSelector">
			<value>
				<![CDATA[
				JMSPriority < 6
				]]>
			</value>
		</property>
	</bean>

The com/landacorp/jms/workmanager resource ref for the messagingTaskExecutor bean resolves to wm/default (the default websphere work manager).

From the Spring javadocs and documentation, it would seem that by default, when not using a transactionManager, DMLC should use full JMS resource caching, but it doesn't appear that's happening.

**gadams00** · Jan 21st, 2012, 01:33 AM

No responses. Hmm.

I've done a *LOT* more detailed testing on this issue and found some interesting results when comparing various DMLC configurations on Websphere 8 and Weblogic 11g (10.3.5). I'm only focusing on concurrentConsumer configurations, since for my use case, I believe I need to have concurrentConsumers configured, unless referencing a CommonJ workmanager makes that need go away. I have certain DMLC instances that handle some very long message processing operations and I wouldn't want to block other requests from being serviced due to one very long request. All this testing was done with Spring 2.5.6.SEC03.

The configurations:

Common parts:

Code:

<bean id="messagingTaskExecutor" class="org.springframework.scheduling.commonj.WorkManagerTaskExecutor">
		<property name="workManagerName" value="com/test/mdp/workmanager" />
		<property name="resourceRef" value="true" />
	</bean>
	
	<jee:jndi-lookup id="connectionFactory" jndi-name="java:comp/env/com/test/mdp/ConnectionFactory" />
	
	<jee:jndi-lookup id="testQueue" jndi-name="java:comp/env/com/test/mdp/TestQueue" />
	
	<bean id="textMessageListener" class="com.test.mdp.TestMessageListener" />

1. transactionless

Code:

<bean id="messageListenerContainer" class="org.springframework.jms.listener.DefaultMessageListenerContainer">
		<property name="taskExecutor" ref="messagingTaskExecutor" />
		<property name="connectionFactory" ref="connectionFactory" />
		<property name="destination" ref="testQueue" />
		<property name="messageListener" ref="textMessageListener" />
		<property name="concurrentConsumers" value="2" />
	</bean>

2. sessionTransacted

Code:

<bean id="messageListenerContainer" class="org.springframework.jms.listener.DefaultMessageListenerContainer">
		<property name="sessionTransacted" value="true" />
		<property name="taskExecutor" ref="messagingTaskExecutor" />
		<property name="connectionFactory" ref="connectionFactory" />
		<property name="destination" ref="testQueue" />
		<property name="messageListener" ref="textMessageListener" />
		<property name="concurrentConsumers" value="2" />
	</bean>

3. JmsTransactionManager

Code:

<bean id="jmsTransactionManager" class="org.springframework.jms.connection.JmsTransactionManager">
		<property name="connectionFactory" ref="connectionFactory" />
	</bean>


<bean id="messageListenerContainer" class="org.springframework.jms.listener.DefaultMessageListenerContainer">
		<property name="transactionManager" ref="jmsTransactionManager" />
		<property name="taskExecutor" ref="messagingTaskExecutor" />
		<property name="connectionFactory" ref="connectionFactory" />
		<property name="destination" ref="testQueue" />
		<property name="messageListener" ref="textMessageListener" />
		<property name="concurrentConsumers" value="2" />
	</bean>

4. JtaTransactionManager

Code:

<tx:jta-transaction-manager />

<bean id="messageListenerContainer" class="org.springframework.jms.listener.DefaultMessageListenerContainer">
		<property name="transactionManager" ref="transactionManager" />
		<property name="taskExecutor" ref="messagingTaskExecutor" />
		<property name="connectionFactory" ref="connectionFactory" />
		<property name="destination" ref="testQueue" />
		<property name="messageListener" ref="textMessageListener" />
		<property name="concurrentConsumers" value="2" />
	</bean>

And the results

1. transactionless
Websphere 8 - No exceptions, but JMS connection resources are created and closed every time DMLC polls...constant PoolSize of 10.
Weblogic 10.3.5 - No exceptions, flat resource usage, shuts down cleanly.

2. sessionTransacted
Websphere 8 - Again, ConnectionFactory shows constant creation and destruction of resource, with garbage pool sizes (-3? WTF, Websphere thinks it's closed more than it's created). This is probably due to the following exceptions, which seem to happen randomly as DMLC polls, regardless of whether it's received a message or not...

Code:

[1/20/12 15:50:31:889 PST] 0000001f LocalTranCoor W   WLTC0033W: Resource com/test/mdp/ConnectionFactory rolled back in cleanup of LocalTransactionContainment.
[1/20/12 15:50:31:889 PST] 00000025 LocalTransact E   enlist(): It is NOT valid to continue working under a transaction that has already rolledback
[1/20/12 15:50:31:890 PST] 0000001f LocalTranCoor W   WLTC0032W: One or more local transaction resources were rolled back during the cleanup of a LocalTransactionContainment.
[1/20/12 15:50:31:891 PST] 00000026 DefaultMessag 3 org.springframework.jms.listener.AbstractPollingMessageListenerContainer doReceiveAndExecute Consumer [com.ibm.ws.sib.api.jms.impl.JmsMsgConsumerImpl@1f5a9b7a] of session [com.ibm.ws.sib.api.jms.impl.JmsSessionImpl@1f5a9ae8] did not receive a message
[1/20/12 15:50:31:891 PST] 00000026 LocalTranCoor W   WLTC0033W: Resource com/test/mdp/ConnectionFactory rolled back in cleanup of LocalTransactionContainment.
[1/20/12 15:50:31:891 PST] 0000001f LocalTransact E   enlist(): It is NOT valid to continue working under a transaction that has already rolledback
[1/20/12 15:50:31:890 PST] 00000025 ConnectionEve E   J2CA0074E: Unable to enlist connection from resource com/test/mdp/ConnectionFactory with current transaction in method localTransactionStarted due to exception. Initiating destruction of connection. Exception is: javax.resource.ResourceException: Attempt to continue working after transaction rolledback !
	at com.ibm.ejs.j2c.LocalTransactionWrapper.enlist(LocalTransactionWrapper.java:577)
	at com.ibm.ejs.j2c.ConnectionEventListener.localTransactionStarted(ConnectionEventListener.java:845)
	at com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection.localTransactionStarted(JmsJcaManagedConnection.java:929)
	at com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl.getCurrentTransaction(JmsJcaSessionImpl.java:323)
	at com.ibm.ws.sib.api.jms.impl.JmsSessionImpl.getTransaction(JmsSessionImpl.java:1823)
	at com.ibm.ws.sib.api.jms.impl.JmsMsgConsumerImpl.receiveInboundMessage(JmsMsgConsumerImpl.java:1051)
	at com.ibm.ws.sib.api.jms.impl.JmsMsgConsumerImpl.receive(JmsMsgConsumerImpl.java:481)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveMessage(AbstractPollingMessageListenerContainer.java:405)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:308)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:261)
	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:982)
	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:881)
	at org.springframework.scheduling.commonj.DelegatingWork.run(DelegatingWork.java:61)
	at com.ibm.ws.asynchbeans.J2EEContext.run(J2EEContext.java:1178)
	at com.ibm.ws.asynchbeans.WorkWithExecutionContextImpl.go(WorkWithExecutionContextImpl.java:199)
	at com.ibm.ws.asynchbeans.CJWorkItemImpl.run(CJWorkItemImpl.java:236)
	at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1650)

[1/20/12 15:50:31:892 PST] 00000026 LocalTranCoor W   WLTC0032W: One or more local transaction resources were rolled back during the cleanup of a LocalTransactionContainment.
[1/20/12 15:50:31:892 PST] 00000025 ConnectionEve W   J2CA0206W: A connection error occurred.  To help determine the problem, enable the Diagnose Connection Usage option on the Connection Factory or Data Source.
[1/20/12 15:50:31:892 PST] 0000001f ConnectionEve E   J2CA0074E: Unable to enlist connection from resource com/test/mdp/ConnectionFactory with current transaction in method localTransactionStarted due to exception. Initiating destruction of connection. Exception is: javax.resource.ResourceException: Attempt to continue working after transaction rolledback !
	at com.ibm.ejs.j2c.LocalTransactionWrapper.enlist(LocalTransactionWrapper.java:577)
	at com.ibm.ejs.j2c.ConnectionEventListener.localTransactionStarted(ConnectionEventListener.java:845)
	at com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection.localTransactionStarted(JmsJcaManagedConnection.java:929)
	at com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl.getCurrentTransaction(JmsJcaSessionImpl.java:323)
	at com.ibm.ws.sib.api.jms.impl.JmsSessionImpl.getTransaction(JmsSessionImpl.java:1823)
	at com.ibm.ws.sib.api.jms.impl.JmsMsgConsumerImpl.receiveInboundMessage(JmsMsgConsumerImpl.java:1051)
	at com.ibm.ws.sib.api.jms.impl.JmsMsgConsumerImpl.receive(JmsMsgConsumerImpl.java:481)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveMessage(AbstractPollingMessageListenerContainer.java:405)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:308)

...

see next post for continuation...

**gadams00** · Jan 21st, 2012, 01:33 AM

2 (cont'd) sessionTransacted
Weblogic 10.3.5 - No runtime exceptions, flat resource usage, app does not shut down cleanly, throws following exception, but does eventually go to "prepared" state, though it seem to take a long time

Code:

2012-01-20 22:31:52,182 DEBUG:org.springframework.jms.listener.DefaultMessageLis
tenerContainer - Connection stop failed - relying on listeners to perform recove
ry after restart
javax.jms.JMSException: [JMSPool:169801]The JMS method stop may not be called in
side an EJB or servlet
        at weblogic.deployment.jms.JMSExceptions.getJMSException(JMSExceptions.j
ava:22)
        at weblogic.deployment.jms.PooledConnection.stop(PooledConnection.java:2
26)
        at org.springframework.jms.listener.AbstractJmsListeningContainer.stopSh
aredConnection(AbstractJmsListeningContainer.java:434)
        at org.springframework.jms.listener.DefaultMessageListenerContainer.stop
SharedConnection(DefaultMessageListenerContainer.java:707)
        at org.springframework.jms.listener.AbstractJmsListeningContainer.doStop
...
2012-01-20 22:31:52,206 INFO :org.springframework.beans.factory.support.DefaultS
ingletonBeanRegistry - Destroying singletons in org.springframework.beans.factor
y.support.DefaultListableBeanFactory@20f1545: defining beans [messagingTaskExecu
tor,connectionFactory,testQueue,textMessageListener,messageListenerContainer]; r
oot of factory hierarchy
2012-01-20 22:31:52,208 DEBUG:org.springframework.beans.factory.support.Disposab
leBeanAdapter - Invoking destroy() on bean with name 'messageListenerContainer'
2012-01-20 22:31:52,210 DEBUG:org.springframework.jms.listener.AbstractJmsListen
ingContainer - Shutting down JMS listener container
2012-01-20 22:31:52,211 DEBUG:org.springframework.jms.listener.DefaultMessageLis
tenerContainer - Waiting for shutdown of message listener invokers

3. JmsTransactionManager
Websphere 8 - No exceptions, ConnectionFactory resources flat, PoolSize=3.
Weblogic 10.3.5 - you have to configure your ConnectionFactory as non-XA, else you'll receive constant exceptions about being unable to commit JMS Transaction. With a non-XA ConnectionFactory, there are no exceptions, flat resource usage, and the app shuts down cleanly.

4. JtaTransactionManager
Websphere 8 - No exceptions, ConnectionFactory resources flat, PoolSize=3.
Weblogic 10.3.5 - No exceptions, flat resource usage, shuts down cleanly.

Does anyone have any ideas as to the strange behavior on websphere? It appears the only workable option is to use transactions, either through a JmsTransactionManager, or through a JtaTransactionManager. I'm not sure I need transactions at all in my particular use cases. We don't care about the messages from the queue being rolled back under any circumstances. We catch all exceptions in our onMessage methods and log them, so that nothing should ever place the message back on the queue. Our DMLC instances do database work, but the transactionality for that should be handled by the standard JTA transaction manager and annotation-driven spring transactional support we use in our DAOs, unless I'm mistaken. Transactions at the JMS level seem like overkill in my use case, and it seems a shame that I'm forced to use them on Websphere.

**gadams00** · Feb 21st, 2012, 01:02 PM

another update: on websphere with concurrentConsumers and no transactionManager specified the messaging provider leaks connections, eventually consuming all heap space and resulting in OutOfMemoryException. Setting receiveTimeout to "1" makes this happen very quickly, since it leaks a connection on each DMLC poll.

This is really aggravating and I don't know whether it's a Spring bug or a websphere bug. Any information anyone can provide would be extremely helpful.

**Gary Russell** · Feb 21st, 2012, 01:44 PM

Apologies for not replying earlier; looking back at your original post, it seems you are seeing the exact opposite of what is expected (and indeed what I saw when working at a customer [with a different JMS provider] at the end of last year).

Certainly I saw that, when an external transaction manager (in that case, JmsTransactionManager) was inadvertently specified, no caching occurred. This is set up in the initialize() method...

Code:

public void initialize() {
	// Adapt default cache level.
	if (this.cacheLevel == CACHE_AUTO) {
		this.cacheLevel = (getTransactionManager() != null ? CACHE_NONE : CACHE_CONSUMER);
	}
...

In that particular environment, we fixed the problem by simply removing the injection of bogus transaction manager into the DMLC.

Either this, or leaving the JmsTransaction manager in place and explicitly setting the cacheLevel to CACHE_CONSUMER (3) worked.

In both cases, the repeated open/close of the connection was avoided (sessionTransacted was "true").

So, I am confused by your observations; perhaps you can attach some TRACE level logs as well as trying explicitly setting the cacheLevel?

**gadams00** · Feb 21st, 2012, 06:33 PM

Would you expect to see leaking connections with no transactionManager and sessionTransacted set to false?

**Gary Russell** · Feb 21st, 2012, 09:23 PM

Nope; and I just ran a test with a DMLC and no TM and sessionTransacted=false and, as expected, the same Consumer/Session/Connection is used each time.

As I mentioned, a TRACE level log shows this (at least with ActiveMQ)...

Code:

2012-02-21 22:18:59,156 [org.springframework.jms.listener.DefaultMessageListenerContainer#0-1] TRACE:
 org.springframework.jms.listener.DefaultMessageListenerContainer - Consumer [Cached JMS MessageConsumer: 
ActiveMQMessageConsumer { value=ID:myhost-60179-1329880731804-2:1:1:1, started=true }] of session [Cached JMS Session: 
ActiveMQSession {id=ID:myhost-60179-1329880731804-2:1:1,started=true}] did not receive a message

Even if your vendor doesn't show a unique ID for the consumer, it's easy enough to verify; just set a breakpoint in doReceiveAndExecute().

**gadams00** · Feb 21st, 2012, 11:37 PM

I turned on trace logging in websphere with sessionTransacted=false and no transactionManager. I can observe JMS Connections being constantly created and destroyed, but keeping a constant pool size of 10. I used the following trace levels:

*=info: org.springframework.jms.*=all: SIBJmsRa=all

Geez, websphere logging is a complete nightmare. Here's a snippet from initial startup where spring is trying to establish a shared JMS Connection:

Code:

[2/21/12 21:14:47:105 PST] 0000000c DefaultMessag 1 org.springframework.jms.listener.AbstractJmsListeningContainer establishSharedConnection Established shared JMS Connection

[2/21/12 21:14:47:105 PST] 00000022 JmsJcaConnect >  createSession (com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionImpl) [:/1f18076b] Entry

                                 false

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaConnect 3   (com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionImpl) [:] clearing first session

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaSession >  close (com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl) [:/1f17da2d] Entry

                                 false

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaManaged >  sessionClosed (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1ed2c9da] Entry

                                 [com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl@1f17da2d <managedConnection=517130714> <connection=521668459> <transacted=false> <applicationLocalTransaction=null> <reqInfo=[com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionRequestInfo@1f17c555> <userDetails=null> <coreConnection=com.ibm.ws.sib.processor.impl.ConnectionImpl@1ed2c966> <request counter=0>]> <sessionClosed=false> <sessionInvalidated=false>]

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaManaged 3   (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1ed2c9da] Sending connection closed events to the 1 listeners

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaManaged <  sessionClosed (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1ed2c9da] Exit

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaSession <  close (com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl) [:/1f17da2d] Exit

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaConnect 3   (com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionImpl) [:/1f18076b] We have already used the first session... creating a new one

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaConnect >  isRunningInWAS (com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionImpl) [:] Entry

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaConnect <  isRunningInWAS (com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionImpl) [:] Exit

                                 true

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaManaged >  createManagedConnection (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnectionFactoryImpl) [:/1d46f1a3] Entry

                                 [javax.security.auth.Subject@1f18c36d <principals=[]>]

                                 [com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionRequestInfo@1f17c555> <userDetails=null> <coreConnection=com.ibm.ws.sib.processor.impl.ConnectionImpl@1ed2c966> <request counter=0>]

[2/21/12 21:14:47:106 PST] 00000022 JmsJcaManaged >  getUserDetails (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnectionFactoryImpl) [:/1d46f1a3] Entry

                                 [javax.security.auth.Subject@1f18c36d <principals=[]>]

...

This goes on and on

Here's a loop of DMLC polling:

Code:

[2/21/12 21:19:25:364 PST] 00000021 DefaultMessag 1 org.springframework.jms.listener.AbstractPollingMessageListenerContainer doReceiveAndExecute Consumer [com.ibm.ws.sib.api.jms.impl.JmsMsgConsumerImpl@1d255e15] of session [com.ibm.ws.sib.api.jms.impl.JmsSessionImpl@1d255d83] did not receive a message

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaSession >  getCurrentTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl) [:/1d252bbd] Entry

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaSession >  getManagedConnection (com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl) [:/1d252bbd] Entry

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaSession <  getManagedConnection (com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl) [:/1d252bbd] Exit

                                 [com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection@1d24c0e9 <managedConnectionFactory=[com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnectionFactoryImpl@1d46f1a3 <logWriter=java.io.PrintWriter@1d47515c> <busName=crbus> <clientID=null> <userName=null> <password=null> <xaRecoveryAlias=> <nonPersistentMapping=ExpressNonPersistent> <persistentMapping=ReliablePersistent> <durableSubscriptionHome=cic-dev-gaa2Node01.server1-crbus> <readAhead=Default> <temporaryQueueNamePrefix=null> <temporaryTopicNamePrefix=null> <target=null> <targetSignificance=Preferred> <targetTransportChain=null> <targetType=BusMember> <providerEndpoints=null> <connectionProximity=Bus> <shareDataSourceWithCMP=false> <shareDurableSubscriptions=InCluster> <cachedFactory=com.ibm.ws.sib.api.jms.impl.JmsFactoryFactoryImpl@1c00bcb4> <producerDoesNotModifyPayloadAfterSet=false> <consumerDoesNotModifyPayloadAfterGet=false>]> <coreConnection=com.ibm.ws.sib.processor.impl.ConnectionImpl@1d24c075> <localTransaction=[com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection$JmsJcaLocalTransaction@1d251d89 <localSITransaction=null>]> <xaResource=null> <metaData=null> <userDetails=null> <subject=[javax.security.auth.Subject@1d24b3b4 <principals=[]>]> <logWriter=java.io.PrintWriter@1ed30faa> <sessions=[[com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl@1d252bbd <managedConnection=488947945> <connection=488908375> <transacted=false> <applicationLocalTransaction=null> <reqInfo=[com.ibm.ws.sib.api.jmsra.impl.JmsJcaConnectionRequestInfo@1d23eadc> <userDetails=null> <coreConnection=com.ibm.ws.sib.processor.impl.ConnectionImpl@1ed2c966> <request counter=0>]> <sessionClosed=false> <sessionInvalidated=false>]]> <connectionListeners=[com.ibm.ejs.j2c.ConnectionEventListener@488953856]>]

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaManaged >  getCurrentTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1d24c0e9] Entry

                                 [ConnectionManager]@1d4aa3ee

JNDI Name <com/landacorp/jms/CRConnectionFactory>

shareable <true>



[2/21/12 21:19:25:364 PST] 00000021 JmsJcaManaged >  getActiveTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1d24c0e9] Entry

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaManaged <  getActiveTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1d24c0e9] Exit

                                 <null>

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaManaged 3   (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1d24c0e9] Lazy enlisting on the connection manager

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaManaged >  getActiveTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1d24c0e9] Entry

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaManaged <  getActiveTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1d24c0e9] Exit

                                 <null>

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaManaged <  getCurrentTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnection) [:/1d24c0e9] Exit

                                 <null>

[2/21/12 21:19:25:364 PST] 00000021 JmsJcaSession <  getCurrentTransaction (com.ibm.ws.sib.api.jmsra.impl.JmsJcaSessionImpl) [:] Exit

                                 <null>

**Gary Russell** · Feb 22nd, 2012, 09:32 AM

Please show several iterations of the DMLC loop; since you have 2 consumers, we need at least 4 of these...

Code:

[2/21/12 21:19:25:364 PST] 00000021 DefaultMessag 1 org.springframework.jms.listener.AbstractPollingMessageListenerContainer doReceiveAndExecute Consumer [com.ibm.ws.sib.api.jms.impl.JmsMsgConsumerImpl@1d255e15] of session [com.ibm.ws.sib.api.jms.impl.JmsSessionImpl@1d255d83] did not receive a message

I want to determine if the same consumer object (e.g. @1d255e15) is being used for each iteration for each thread.

I assume this 'DefaultMessag 1' is extracted from the thread Id in your log config; if not, we need to be sure to be able to identify each thread.

Thanks.

**gadams00** · Feb 22nd, 2012, 05:09 PM

I've switched to a very small test application that I can redeploy easily in websphere. I've attached a zip containing the trace.log file from several minutes of websphere running with the following trace log levels:

*=info: org.springframework.jms.*=all: com.landacorp.test.*=all: SIBJmsRa=all

and with the following DMLC config:

<bean id="messageListenerContainer" class="org.springframework.jms.listener.DefaultMes sageListenerContainer">
<property name="taskExecutor" ref="messagingTaskExecutor" />
<property name="connectionFactory" ref="connectionFactory" />
<property name="destination" ref="testQueue" />
<property name="messageListener" ref="textMessageListener" />
<property name="concurrentConsumers" value="2" />
</bean>

I believe the "3" from DefaultMessag 3 in the logs above references an "event type" according to websphere logging documentation, whatever that means. However, in wading through the huge amount of logs in the attached trace log, I found this:

Code:

[2/22/12 14:45:38:639 PST] 00000027 JmsJcaManaged 3   (com.ibm.ws.sib.api.jmsra.impl.JmsJcaManagedConnectionFactoryImpl) [:] Connection Request Info core connection no longer available

I can't find any logging where I can see that connections are explicitly getting closed, but these logs are extremely difficult to decipher.

Thread: DefaultMessageListenerContainer and Websphere default JMS provider (SIB)

Thread Tools

Display

DefaultMessageListenerContainer and Websphere default JMS provider (SIB)

Posting Permissions