SL created ARTEMIS-2525:
---------------------------
Summary: Intermittent failure to send
Key: ARTEMIS-2525
URL: https://issues.apache.org/jira/browse/ARTEMIS-2525
Project: ActiveMQ Artemis
Issue Type: Bug
Components: OpenWire
Affects Versions: 2.10.1
Reporter: SL
Hello,
I'm struggling to determine the cause of an issue with sending of messages.
In a embedded artemis broker, an application send messages using the VM
Connector and spring JmsTemplate (5.1.10).
The messages failling are end of batch notifications, and can be sent by two
ways : at the end of the onMessage() of a consumer (of another queue), if
matched a certain threshold, and by a (java) scheduled executor if necessary.
the messages have only headers, no payload.
The sending by the scheduled task tends to fail often; the sending via the
consumer onMessage() much less.
The "client" stacktrace of the failure looks like this
{noformat}
Exception in thread "Timer-0"
org.springframework.jms.UncategorizedJmsException: Uncategorized exception
occurred during JMS processing; nested exception is javax.jms.JMSException
at
org.springframework.jms.support.JmsUtils.convertJmsAccessException(JmsUtils.java:311)
at
org.springframework.jms.support.JmsAccessor.convertJmsAccessException(JmsAccessor.java:185)
at
org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:507)
at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:576)
(...)
Caused by: javax.jms.JMSException
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:464)
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:358)
at
org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQClientProtocolManager.createSessionContext(ActiveMQClientProtocolManager.java:300)
at
org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQClientProtocolManager.createSessionContext(ActiveMQClientProtocolManager.java:249)
at
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl.createSessionChannel(ClientSessionFactoryImpl.java:1348)
at
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl.createSessionInternal(ClientSessionFactoryImpl.java:673)
at
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl.createSession(ClientSessionFactoryImpl.java:298)
at
org.apache.activemq.artemis.jms.client.ActiveMQConnection.authorize(ActiveMQConnection.java:684)
at
org.apache.activemq.artemis.jms.client.ActiveMQConnectionFactory.createConnectionInternal(ActiveMQConnectionFactory.java:920)
at
org.apache.activemq.artemis.jms.client.ActiveMQConnectionFactory.createConnection(ActiveMQConnectionFactory.java:299)
at
org.apache.activemq.artemis.jms.client.ActiveMQConnectionFactory.createConnection(ActiveMQConnectionFactory.java:294)
at
org.messaginghub.pooled.jms.JmsPoolConnectionFactory.createProviderConnection(JmsPoolConnectionFactory.java:650)
at
org.messaginghub.pooled.jms.JmsPoolConnectionFactory$1.makeObject(JmsPoolConnectionFactory.java:107)
at
org.messaginghub.pooled.jms.JmsPoolConnectionFactory$1.makeObject(JmsPoolConnectionFactory.java:104)
at
org.apache.commons.pool2.impl.GenericKeyedObjectPool.create(GenericKeyedObjectPool.java:1041)
at
org.apache.commons.pool2.impl.GenericKeyedObjectPool.addObject(GenericKeyedObjectPool.java:1233)
at
org.messaginghub.pooled.jms.JmsPoolConnectionFactory.createJmsPoolConnection(JmsPoolConnectionFactory.java:704)
at
org.messaginghub.pooled.jms.JmsPoolConnectionFactory.createConnection(JmsPoolConnectionFactory.java:236)
at
org.messaginghub.pooled.jms.JmsPoolConnectionFactory.createConnection(JmsPoolConnectionFactory.java:231)
at
org.springframework.jms.support.JmsAccessor.createConnection(JmsAccessor.java:196)
at
org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:494)
Caused by: ActiveMQInternalErrorException[errorType=INTERNAL_ERROR message=null]
... 28 more{noformat}
The "server" side seems to produce traces that are related to the client side
trace, at matching datetimes
{noformat}
2019-10-17 11:20:13,948 DEBUG {Thread-5
(ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@6b723061)}
[o.a.a.artemis.core.server.impl.QueueImpl] : QueueImpl[name=FullEvent.2.In,
postOffice=PostOfficeImpl
[server=ActiveMQServerImpl::serverUUID=c7fa0fe7-6688-11e9-9127-005056aaab0e],
temp=false]@72d59969::All the consumers were busy, giving up now{noformat}
After the failure if we send messages (to another queue via ssl connection) to
trigger the application consumers, the failed message reappears and its further
processing is handled by its consumer as expected.
The target queue with the issue is an internal queue (only used via the vm
connector, not exposed to outside consumers).
I've meddled with various parameters in the broker and activemq connection
factory (max consumers, pool size, timeout, disabling advisatory etc) moving
values up far above supposed requirements with little success. Something its
seems to fall in place and work for a moment.
I've looked a bit in the internal code used, mostly QueueImpl, which produces
the "busy" debug message, put I have not been able to détermine anyting useful
from it.
The pooledJms is 1.0.6 and activemq-client is 5.14.5 ;
Any pointers to potential areas of investigation or best pratices to try narrow
it down to a publishable test case is appreciated.
Regards,
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
