[AMQ-8052] Producer thread stuck in socket write operation

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 5.15.3
• Component/s: JMS client
• Assignee: Jean-Baptiste Onofré
• Reporter: Guillaume Charon
• Created: 12/Oct/20 13:04
• Updated: 04/Feb/21 08:59

Description

I have a JMS Client written in Java/Spring and using activemq-client maven library. This client is intended to produce approx. 25000 msg per minute to a AMQ broker which is hosted by a different server.

When the system is overloaded, it can produce 50000 msg per minute. At that point, our production server faces an issue which blocks the entire system : one thread get stuck in the socket write operation, and the server can't send messages to the broker anymore.

 

Here is one part of the stacktrace from the stuck thread :

java.lang.Thread.State: RUNNABLE
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
at org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:115)
at java.io.DataOutputStream.flush(DataOutputStream.java:123)
at org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:194)
at org.apache.activemq.transport.AbstractInactivityMonitor.doOnewaySend(AbstractInactivityMonitor.java:335)
at org.apache.activemq.transport.AbstractInactivityMonitor.oneway(AbstractInactivityMonitor.java:317)
at org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:94)
at org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:116)
at org.apache.activemq.transport.failover.FailoverTransport.oneway(FailoverTransport.java:668)
- locked <0x0000000088f813f0> (a java.lang.Object)
at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68)
at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
at org.apache.activemq.ActiveMQConnection.doAsyncSendPacket(ActiveMQConnection.java:1308)
at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1302)
at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1956)
- locked <0x0000000091434658> (a java.lang.Object)
at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:288)
at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:223)
at org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:269)
at org.springframework.jms.connection.CachedMessageProducer.send(CachedMessageProducer.java:155)
at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:631)
at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:608)

All the other threads are waiting for the ReentrantLock :

java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000088fd9f28> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:66)
at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
at org.apache.activemq.ActiveMQConnection.doAsyncSendPacket(ActiveMQConnection.java:1308)
at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1302)
at org.apache.activemq.ActiveMQSession.<init>(ActiveMQSession.java:255)
at org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:338)
at org.springframework.jms.connection.SingleConnectionFactory.createSession(SingleConnectionFactory.java:481)
at org.springframework.jms.connection.CachingConnectionFactory.getSession(CachingConnectionFactory.java:232)
at org.springframework.jms.connection.SingleConnectionFactory$SharedConnectionInvocationHandler.invoke(SingleConnectionFactory.java:648)
at com.sun.proxy.$Proxy212.createSession(Unknown Source)
at org.springframework.jms.support.JmsAccessor.createSession(JmsAccessor.java:208)
at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:495)
at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:584)
at org.springframework.jms.core.JmsTemplate.convertAndSend(JmsTemplate.java:691)
at org.springframework.jms.core.JmsTemplate.convertAndSend(JmsTemplate.java:671)

I can't understand why it's stuck here because :

1. TCP is a reliable protocol : if the packet is not sent, it should be retried
2. If the connection to AMQ was lost, I should see something about that in the log files
3. If there is a problem with the buffer (because too many data to send at the same time maybe?), it should be stuck for few seconds only = the time needed to flush the buffer

 

 

I saw in the AMQ-1993 issue that soWriteTimeout could do the job, but I can't reproduce the problem with a unit test (maybe because producer and broker are both on localhost), so I can't check this.

And still, I want to understand why the thread is stuck with your help !

 

 

NB : the client (= producer) is configured with a CachingConnectionFactory (sessionCacheSize=100) and using a JndiConnectionFactory (spring-jms 5.1.3).

 

 

Thank you for your help.