JMS DefaultMessageListenerContainer recovery fails

[pigwin32]

Hi

I am using Sun's Open Message Queue and if I restart the broker my client fails to reconnect. Any assistance with this would be greatly appreciated :

INFO   | jvm 1    | 2008/08/02 14:55:38 | 2/08/2008 14:55:38 com.sun.messaging.jmq.jmsclient.ExceptionHandler logCaughtException
INFO   | jvm 1    | 2008/08/02 14:55:38 | WARNING: [I500]: Caught JVM Exception: java.net.SocketException: Connection reset
INFO   | jvm 1    | 2008/08/02 14:55:38 | 2/08/2008 14:55:38 com.sun.messaging.jmq.jmsclient.ExceptionHandler logCaughtException
INFO   | jvm 1    | 2008/08/02 14:55:38 | WARNING: [I500]: Caught JVM Exception: com.sun.messaging.jms.JMSException: [C4002]: Read packet failed. - cause: java.net.SocketException: Connection reset
INFO   | jvm 1    | 2008/08/02 14:55:38 | java.net.SocketException: Connection reset
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.fill(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.read1(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.read(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readFully(ReadOnlyPacket.java:271)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readFixedHeader(ReadOnlyPacket.java:191)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readPacket(ReadOnlyPacket.java:151)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadWritePacket.readPacket(ReadWritePacket.java:82)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ProtocolHandler.readPacket(ProtocolHandler.java:1738)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ReadChannel.run(ReadChannel.java:1160)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | com.sun.messaging.jms.JMSException: [C4002]: Read packet failed. - cause: java.net.SocketException: Connection reset
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ExceptionHandler.getJMSException(ExceptionHandler.java:380)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ExceptionHandler.handleException(ExceptionHandler.java:331)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ProtocolHandler.readPacket(ProtocolHandler.java:1776)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ReadChannel.run(ReadChannel.java:1160)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | Caused by: java.net.SocketException: Connection reset
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.fill(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.read1(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.read(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readFully(ReadOnlyPacket.java:271)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readFixedHeader(ReadOnlyPacket.java:191)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readPacket(ReadOnlyPacket.java:151)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadWritePacket.readPacket(ReadWritePacket.java:82)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ProtocolHandler.readPacket(ProtocolHandler.java:1738)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	... 2 more
INFO   | jvm 1    | 2008/08/02 14:55:38 | 2008-08-02 14:55:38,140 ERROR org.springframework.jms.listener.DefaultMessageListenerContainer - Setup of JMS message listener invoker failed - trying to recover
INFO   | jvm 1    | 2008/08/02 14:55:38 | com.sun.messaging.jms.JMSException: [C4063]: Cannot perform operation, consumer is closed.
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.MessageConsumerImpl.receive(MessageConsumerImpl.java:483)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveMessage(AbstractPollingMessageListenerContainer.java:375)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:300)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:254)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:870)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:810)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | Caused by: com.sun.messaging.jms.JMSException: [C4002]: Read packet failed. - cause: java.net.SocketException: Connection reset
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ExceptionHandler.getJMSException(ExceptionHandler.java:380)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ExceptionHandler.handleException(ExceptionHandler.java:331)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ProtocolHandler.readPacket(ProtocolHandler.java:1776)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ReadChannel.run(ReadChannel.java:1160)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	... 1 more
INFO   | jvm 1    | 2008/08/02 14:55:38 | Caused by: java.net.SocketException: Connection reset
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.net.SocketInputStream.read(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.fill(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.read1(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at java.io.BufferedInputStream.read(Unknown Source)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readFully(ReadOnlyPacket.java:271)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readFixedHeader(ReadOnlyPacket.java:191)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadOnlyPacket.readPacket(ReadOnlyPacket.java:151)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.io.ReadWritePacket.readPacket(ReadWritePacket.java:82)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	at com.sun.messaging.jmq.jmsclient.ProtocolHandler.readPacket(ProtocolHandler.java:1738)
INFO   | jvm 1    | 2008/08/02 14:55:38 | 	... 2 more
INFO   | jvm 1    | 2008/08/02 14:55:38 | 2008-08-02 14:55:38,187 INFO org.springframework.jms.listener.DefaultMessageListenerContainer - Successfully refreshed JMS Connection
INFO   | jvm 1    | 2008/08/02 14:55:43 | 2008-08-02 14:55:43,187 ERROR org.springframework.jms.listener.DefaultMessageListenerContainer - Setup of JMS message listener invoker failed - trying to recover
INFO   | jvm 1    | 2008/08/02 14:55:43 | javax.jms.IllegalStateException: [C4062]: Cannot perform operation, connection is closed.
INFO   | jvm 1    | 2008/08/02 14:55:43 | 	at com.sun.messaging.jmq.jmsclient.ConnectionImpl.checkConnectionState(ConnectionImpl.java:2385)

Config (tsb.schedule.MqConnectionFactory extends com.sun.messaging.ConnectionFactory):

    <!-- Open MQ JMS configuration - constructor argument is location of mq broker -->
    <bean id="jmsConnectionFactory" class="tsb.schedule.MqConnectionFactory">
        <constructor-arg type="java.lang.String" value="davidcentos"/>
    </bean>

    <bean id="businessQueue" class="com.sun.messaging.Queue">
        <constructor-arg type="java.lang.String" value="businessQueue"/>
    </bean>

    <bean id="jmsFactory" class="org.springframework.jms.connection.SingleConnectionFactory">
        <property name="targetConnectionFactory" ref="jmsConnectionFactory" />
    </bean>

    <!--
        Receiving
    -->
    <bean id="jmsContainer" class="org.springframework.jms.listener.DefaultMessageListenerContainer">
        <property name="connectionFactory" ref="jmsFactory" />
        <property name="destination" ref="businessQueue"/>
        <property name="messageListener" ref="scheduleListener"/>
    </bean>

[donjigweed]

It's not specific to Sun's OMQ. I believe it happens with any message broker. I've seen this issue with Websphere MQ, ActiveMQ, and Weblogic.

You need to set the cacheLevelName property on the container to CACHE_CONNECTION. Anything more is too aggressive apparently for the recovery to function properly.

[pigwin32]

Wow, thanks for the reply. I would try your suggestion except I left the position on 15 August. It was an awful place to work and I'm much happier not being there but I did have to leave behind a few loose ends I wasn't able to tidy up before I left - this was one of them.

[Harry Lime]

I was having this same problem and the fix was to add transaction management. So adding

<property name="transactionManager" ref="jmsTransactionManager"/>

to my DefaultMessageListenerContainer config. And adding

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

did the trick.

Searching the web didn't show up this solution... so that's why I'm posting it here.