publish() call to remote JMS server hangs

[skarthik]

Hi,

 This is rather long post as it took me a while to narrow down the problem.

 We are running activeMQ RC2 server on a windows XP machine and a simple JMS client test-program on another remote XP machine within the same LAN subnet. The test-program opens one JMS connection to the activeMQ server, establishes one session (with auto acknowledge), and creates one publisher on a topic on the session. Then in a loop, it creates an ObjectMessage and publishes it with PERSISTENT DeliveryMode, peppered by Thread.sleep() calls after each publish. The following snippet provides an example:

         TopicConnectionFactory tcf = (TopicConnectionFactory) jndiCtx.lookup (tcfName);
         Topic topic = (Topic) jndiCtx.lookup (topicName);

         TopicConnection jmsCon = tcf.createTopicConnection();
         TopicSession session = jmsCon.createTopicSession (false, Session.AUTO_ACKNOWLEDGE);
         TopicPublisher publisher = session.createPublisher (topic);

         while (true) {
            ObjectMessage om = session.createObjectMessage ();
            om.setObject ("TESTSTRING");
            publisher.publish (om, DeliveryMode.PERSISTENT, 9, 20000);

            Thread.sleep (20000);
         }


 It was found that when we disconnect the LAN cable from the client machine (to simulate network outage), if the test client tries to publish an ObjectMessage before activeMQ client stub detects the network disconnect, the publish call hangs.

 After further analysis, we found that even setting simple string payload to the ObjectMessage as shown in the following code snippet causes the hang.

         ObjectMessage om = session.createObjectMessage ();
         om.setObject ("TESTSTRING");
         publisher.publish (om, DeliveryMode.PERSISTENT, 9, 20000);

 But using a byte array (byte[]) as payload does not cause an hang.

        byte[] payload; // populated by reading a specified input ascii file

         ObjectMessage om = session.createObjectMessage ();
         om.setObject (payload);
         publisher.publish (om, DeliveryMode.PERSISTENT, 9, 20000);

 Also setting a complex java serializable class instance as payload causes a hang, but an instance of almost similar class, but with an additional byte[] array attribute does not cause the publish() call to hang.

 Wanted to clarify that this hang is observered only in the test case scenario involving LAN disconnects. In normal cases the same messages flow sucessfully between the multiple remote producers and consumers. Also when I say the publish() call does not hang, I meant the publish() class throws the following exception which is the normal expected behavior.

javax.jms.JMSException: Connection reset by peer: socket write error at
 org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:57)
        at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1118)
        at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1524)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:462)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:384)
        at org.apache.activemq.ActiveMQTopicPublisher.publish(ActiveMQTopicPublisher.java:151)
                at com.nec.tdd.tools.platformX.util.PingJMSMsg$Publisher.publishMessage(PingJMSMsg.java:122)
        at com.nec.tdd.tools.platformX.util.PingJMSMsg$Publisher.run(PingJMSMsg.java:102)
Caused by: java.net.SocketException: Connection reset by peer: socket write error at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
        at org.apache.activemq.transport.tcp.TcpBufferedOutputStream.write(TcpBufferedOutputStream.java:95)
        at java.io.DataOutputStream.write(DataOutputStream.java:85)
        at org.apache.activemq.openwire.v1.BaseDataStreamMarshaller.tightMarshalByteSequence2(BaseDataStreamMarshaller.java:403)
        at org.apache.activemq.openwire.v1.MessageMarshaller.tightMarshal2(MessageMarshaller.java:160)
        at org.apache.activemq.openwire.v1.ActiveMQMessageMarshaller.tightMarshal2(ActiveMQMessageMarshaller.java:88)
        at org.apache.activemq.openwire.v1.ActiveMQObjectMessageMarshaller.tightMarshal2(ActiveMQObjectMessageMarshaller.java:88)
        at org.apache.activemq.openwire.OpenWireFormat.marshal(OpenWireFormat.java:240)
        at org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:120)
        at org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:141)
        at org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:86)
        at org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:77)
        at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
        at org.apache.activemq.transport.ResponseCorrelator.asyncRequest(ResponseCorrelator.java:63)
        at org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:68)
        at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1108)
        ... 6 more

  I hope this was helpful and would lead to a fix as this is a crital test scenario for us.

Thanks in advance

regards
karthik

[skarthik]

Hi,

After futher investigation, it seems that the problem is not related to the type of Object being serialized as payload, but rather the size of the object. It seems that payloads of less than 64KB size causes the publish() call to hang, while payloads larger than 64KB does not.

 The problem is that in our application the publish is done under a synchronized lock, and if the call hangs, other publish/close/cleanup/reconnect code will be deadlocked.

Thanks,
karthik

[Hiram Chirino]

Hi Karthik,

Posting a thread dump from your hung client would help us tremendously.

On 4/17/06, skarthik <karthik.sethuraman@...> wrote:

>
> Hi,
>
> After futher investigation, it seems that the problem is not related to the
> type of Object being serialized as payload, but rather the size of the
> object. It seems that payloads of less than 64KB size causes the publish()
> call to hang, while payloads larger than 64KB does not.
>
>  The problem is that in our application the publish is done under a
> synchronized lock, and if the call hangs, other
> publish/close/cleanup/reconnect code will be deadlocked.
>
> Thanks,
> karthik
> --
> View this message in context: http://www.nabble.com/publish%28%29-call-to-remote-JMS-server-hangs-t1446830.html#a3956186
> Sent from the ActiveMQ - User forum at Nabble.com.
>
>

--
Regards,
Hiram

[James.Strachan]

Your operating system should at some point realise that the socket is
dead and kill the socket, unblocking the send thread with an
IOException.

The 'hang' most likely lasts for as long as your default TCP socket
timeout on your OS. You could try set more aggresive timeouts...

http://activemq.org/TCP+Transport+Reference

(e.g. using soTimeout=2000)


On 4/17/06, skarthik <karthik.sethuraman@...> wrote:

>
> Hi,
>
> After futher investigation, it seems that the problem is not related to the
> type of Object being serialized as payload, but rather the size of the
> object. It seems that payloads of less than 64KB size causes the publish()
> call to hang, while payloads larger than 64KB does not.
>
>  The problem is that in our application the publish is done under a
> synchronized lock, and if the call hangs, other
> publish/close/cleanup/reconnect code will be deadlocked.
>
> Thanks,
> karthik
> --
> View this message in context: http://www.nabble.com/publish%28%29-call-to-remote-JMS-server-hangs-t1446830.html#a3956186
> Sent from the ActiveMQ - User forum at Nabble.com.
>
>

--

James
-------
http://radio.weblogs.com/0112098/

[skarthik]

Hi,

Here are two thread dumps, plus the exception reported by the ExceptionListener registered on the JMS TopicConnection. I hope this helps, as setting an aggressive timeout on socket as suggested by James may not be a viable option.

ExceptionListener reports following error within 10 seconds after network failure

2006-04-18 11:10:49,127 [tcp:///143.102.32.175:8000] - Got JMSError notification
javax.jms.JMSException: Connection reset
        at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:45)
        at org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1397)
        at org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1406)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
        at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
        at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:152)
        at java.lang.Thread.run(Thread.java:534)
Caused by: java.net.SocketException: Connection reset
        at java.net.SocketInputStream.read(SocketInputStream.java:168)
        at org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:48)
        at org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:55)
        at java.io.DataInputStream.readInt(DataInputStream.java:443)
        at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:270)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:138)
        ... 1 more

First thread dump within a minute after the connection reset reported by ExceptionListener

Full thread dump Java HotSpot(TM) Client VM (1.4.2_03-b02 mixed mode):

"DestroyJavaVM" prio=5 tid=0x00036198 nid=0xc98 waiting on condition [0..7fad8]

"Thread-1" prio=5 tid=0x02dce450 nid=0xa94 in Object.wait() [303f000..303fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x10059c58> (a org.apache.activemq.transport.FutureResponse)
        at java.lang.Object.wait(Object.java:429)
        at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.waitFor(FutureTask.java:267)
        at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.get(FutureTask.java:117)
        - locked <0x10059c58> (a org.apache.activemq.transport.FutureResponse)
        at org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:44)
        - locked <0x10059c58> (a org.apache.activemq.transport.FutureResponse)
        at org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:69)
        at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1108)
        at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1524)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:462)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:384)
        at org.apache.activemq.ActiveMQTopicPublisher.publish(ActiveMQTopicPublisher.java:151)
        at com.nec.tdd.tools.platformX.util.PingJMSMsg$Publisher.publishMessage(PingJMSMsg.java:122)
        at com.nec.tdd.tools.platformX.util.PingJMSMsg$Publisher.run(PingJMSMsg.java:102)

"ActiveMQ Scheduler" daemon prio=5 tid=0x02db53f8 nid=0x7c0 in Object.wait() [2fff000..2fffd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x10560500> (a java.lang.Object)
        at java.lang.Object.wait(Object.java:398)
        at edu.emory.mathcs.backport.java.util.concurrent.TimeUnit.timedWait(TimeUnit.java:301)
        at edu.emory.mathcs.backport.java.util.concurrent.DelayQueue.take(DelayQueue.java:156)
        - locked <0x10560500> (a java.lang.Object)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:590)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:477)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
        at java.lang.Thread.run(Thread.java:534)

"ActiveMQ Scheduler" daemon prio=5 tid=0x02dd03c8 nid=0x418 in Object.wait() [2fbf000..2fbfd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x10560500> (a java.lang.Object)
        at java.lang.Object.wait(Object.java:398)
        at edu.emory.mathcs.backport.java.util.concurrent.TimeUnit.timedWait(TimeUnit.java:301)
        at edu.emory.mathcs.backport.java.util.concurrent.DelayQueue.take(DelayQueue.java:156)
        - locked <0x10560500> (a java.lang.Object)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:590)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:477)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
        at java.lang.Thread.run(Thread.java:534)

"Signal Dispatcher" daemon prio=10 tid=0x0003e408 nid=0xecc waiting on condition [0..0]

"Finalizer" daemon prio=9 tid=0x009bffd0 nid=0xcd8 in Object.wait() [2b5f000..2b5fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x104fd240> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x104fd240> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x009beba0 nid=0x8e0 in Object.wait() [2b1f000..2b1fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x104fd2a8> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:429)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
        - locked <0x104fd2a8> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=5 tid=0x009fb6b0 nid=0xdb8 runnable

"VM Periodic Task Thread" prio=10 tid=0x009fcb58 nid=0x7a0 waiting on condition

"Suspend Checker Thread" prio=10 tid=0x009c2508 nid=0xe64 runnable

Second thread dump about approx 15 mins after the first one

Full thread dump Java HotSpot(TM) Client VM (1.4.2_03-b02 mixed mode):

"DestroyJavaVM" prio=5 tid=0x00036198 nid=0xc98 waiting on condition [0..7fad8]

"Thread-1" prio=5 tid=0x02dce450 nid=0xa94 in Object.wait() [303f000..303fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x10059c58> (a org.apache.activemq.transport.FutureResponse)
        at java.lang.Object.wait(Object.java:429)
        at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.waitFor(FutureTask.java:267)
        at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.get(FutureTask.java:117)
        - locked <0x10059c58> (a org.apache.activemq.transport.FutureResponse)
        at org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:44)
        - locked <0x10059c58> (a org.apache.activemq.transport.FutureResponse)
        at org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:69)
        at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1108)
        at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1524)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:462)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:384)
        at org.apache.activemq.ActiveMQTopicPublisher.publish(ActiveMQTopicPublisher.java:151)
        at com.nec.tdd.tools.platformX.util.PingJMSMsg$Publisher.publishMessage(PingJMSMsg.java:122)
        at com.nec.tdd.tools.platformX.util.PingJMSMsg$Publisher.run(PingJMSMsg.java:102)

"ActiveMQ Scheduler" daemon prio=5 tid=0x02db53f8 nid=0x7c0 in Object.wait() [2fff000..2fffd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x10560500> (a java.lang.Object)
        at java.lang.Object.wait(Object.java:429)
        at edu.emory.mathcs.backport.java.util.concurrent.DelayQueue.take(DelayQueue.java:152)
        - locked <0x10560500> (a java.lang.Object)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:590)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:477)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
        at java.lang.Thread.run(Thread.java:534)

"ActiveMQ Scheduler" daemon prio=5 tid=0x02dd03c8 nid=0x418 in Object.wait() [2fbf000..2fbfd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x10560500> (a java.lang.Object)
        at java.lang.Object.wait(Object.java:429)
        at edu.emory.mathcs.backport.java.util.concurrent.DelayQueue.take(DelayQueue.java:152)
        - locked <0x10560500> (a java.lang.Object)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:590)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:477)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
        at java.lang.Thread.run(Thread.java:534)

"Signal Dispatcher" daemon prio=10 tid=0x0003e408 nid=0xecc waiting on condition [0..0]

"Finalizer" daemon prio=9 tid=0x009bffd0 nid=0xcd8 in Object.wait() [2b5f000..2b5fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x104fd240> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
        - locked <0x104fd240> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x009beba0 nid=0x8e0 in Object.wait() [2b1f000..2b1fd8c]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x104fd2a8> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:429)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
        - locked <0x104fd2a8> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=5 tid=0x009fb6b0 nid=0xdb8 runnable

"VM Periodic Task Thread" prio=10 tid=0x009fcb58 nid=0x7a0 waiting on condition

"Suspend Checker Thread" prio=10 tid=0x009c2508 nid=0xe64 runnable

thanks
karthik

[skarthik]

Hi,

 We just found that similar situation (publish call hanging) occurs after the following errors were reported by the ExceptionListener. These errors are different from network failure described in the previous post.

 These were noticed in our application environment which consists of 1 JMS server (activeMQ) and about 10 JMS client processes all running on same host machine (for now), each of which may have about 4-10 TopicSessions (producer or consumer) each. Any given error was observed in only one of the clients at a time.

 The purpose of this post was just to clarify that the publish call hanging is not related to just the socket reset error case.

2006-04-12 23:41:05,872 [tcp:///143.102.32.213:8000] - [ChannelListMgr] Got JMSError notification
javax.jms.JMSException: java.io.EOFException
        at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:45)
        at org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1397)
        at org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1406)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
        at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
        at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:152)
        at java.lang.Thread.run(Thread.java:534)
Caused by: java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:448)
        at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:270)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:138)
        ... 1 more


2006-04-13 09:09:48,296 [tcp:///143.102.32.213:8000] - [ChannelListMgr] Got JMSError notification
javax.jms.JMSException: Unknown data type: -118
        at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:45)
        at org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1397)
        at org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1406)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
        at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
        at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:152)
        at java.lang.Thread.run(Thread.java:534)
Caused by: java.io.IOException: Unknown data type: -118
        at org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:341)
        at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:272)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:138)
        ... 1 more

       
2006-04-14 14:58:35,781 [ActiveMQ Scheduler] - [ChannelListMgr] Got JMSError notification
javax.jms.JMSException: Channel was inactive for too long.
        at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:45)
        at org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1397)
        at org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1406)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
        at org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
        at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
        at org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
        at org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
        at org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
        at edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
        at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:534)
Caused by: org.apache.activemq.transport.InactivityIOException: Channel was inactive for too long.
        ... 10 more

 Hope this helps.

Thanks
karthik

[Hiram Chirino]

Looks like the ResponseCorrelator is not releasing outstanding
requests when an async exception is encountered.  Working on a fix
now.

see:
http://issues.apache.org/activemq/browse/AMQ-691


On 4/18/06, skarthik <karthik.sethuraman@...> wrote:

>
> Hi,
>
>  We just found that similar situation (publish call hanging) occurs after
> the following errors were reported by the ExceptionListener. These errors
> are different from network failure described in the previous post.
>
>  These were noticed in our application environment which consists of 1 JMS
> server (activeMQ) and about 10 JMS client processes all running on same host
> machine (for now), each of which may have about 4-10 TopicSessions (producer
> or consumer) each. Any given error was observed in only one of the clients
> at a time.
>
>  The purpose of this post was just to clarify that the publish call hanging
> is not related to just the socket reset error case.
>
> 2006-04-12 23:41:05,872 [tcp:///143.102.32.213:8000] - [ChannelListMgr] Got
> JMSError notification
> javax.jms.JMSException: java.io.EOFException
>         at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:45)
>         at
> org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1397)
>         at
> org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1406)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
>         at
> org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
>         at
> org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:152)
>         at java.lang.Thread.run(Thread.java:534)
> Caused by: java.io.EOFException
>         at java.io.DataInputStream.readInt(DataInputStream.java:448)
>         at
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:270)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:138)
>         ... 1 more
>
>
> 2006-04-13 09:09:48,296 [tcp:///143.102.32.213:8000] - [ChannelListMgr] Got
> JMSError notification
> javax.jms.JMSException: Unknown data type: -118
>         at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:45)
>         at
> org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1397)
>         at
> org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1406)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
>         at
> org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
>         at
> org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:152)
>         at java.lang.Thread.run(Thread.java:534)
> Caused by: java.io.IOException: Unknown data type: -118
>         at
> org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:341)
>         at
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:272)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:138)
>         ... 1 more
>
>
> 2006-04-14 14:58:35,781 [ActiveMQ Scheduler] - [ChannelListMgr] Got JMSError
> notification
> javax.jms.JMSException: Channel was inactive for too long.
>         at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:45)
>         at
> org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1397)
>         at
> org.apache.activemq.ActiveMQConnection.onException(ActiveMQConnection.java:1406)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:102)
>         at
> org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
>         at
> org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
>         at
> org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at
> org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at
> org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at
> edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         at
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Thread.java:534)
> Caused by: org.apache.activemq.transport.InactivityIOException: Channel was
> inactive for too long.
>         ... 10 more
>
>  Hope this helps.
>
> Thanks
> karthik
> --
> View this message in context: http://www.nabble.com/publish%28%29-call-to-remote-JMS-server-hangs-t1446830.html#a3975557
> Sent from the ActiveMQ - User forum at Nabble.com.
>
>

--
Regards,
Hiram