Details
-
Bug
-
Status: Closed
-
Minor
-
Resolution: Fixed
-
0.44.0
-
None
Description
Exceptions created within the clients lower layer were often [re]thrown by the clients upper layer, meaning they lack call stack from the applications perspective. Within the JMS 2 API additions these exceptions are often caught and wrapped in JMSRuntimeException equivalents, as required by the API not allowing for checked exceptions. This means the same general failure did contain application perspective call stack in those cases, creating a behaviour inconsistency depending on the API being used. The client should be updated to consistently ensure application call stack is available in such cases.
================
Original Description:
Please investigate about including full stack traces which include calling methods in all AMQ stack traces. We are expecting better and good full stack traces to easily identify the offending code.
We are using qpid libs (qpid-jms-client-0.40.0.redhat-00001.jar).
Below output is 2 tests run by Junit. The first highlighted in RED does not include any com.fedex etc calling method. It does manage to identify the method name.
The 2^nd^ test shows the desired full stack trace.
We are seeing this behavior so many times. It appears that most/any time AMQ hands off a task to a worker thread, the calling method is not included in any failures reported.
1) testSendMessageWithCompletionListener(junitTests.com.fedex.mi.decorator.jms.JmsMessageProducerTests)javax.jms.InvalidDestinationException: AMQ119002: target address does not exist [condition = amqp:not-found]
at org.apache.qpid.jms.provider.amqp.AmqpSupport.convertToException(AmqpSupport.java:150)
at org.apache.qpid.jms.provider.amqp.AmqpSupport.convertToException(AmqpSupport.java:117)
at org.apache.qpid.jms.provider.amqp.builders.AmqpResourceBuilder.handleClosed(AmqpResourceBuilder.java:185)
at org.apache.qpid.jms.provider.amqp.builders.AmqpResourceBuilder.processRemoteClose(AmqpResourceBuilder.java:129)
at org.apache.qpid.jms.provider.amqp.AmqpProvider.processUpdates(AmqpProvider.java:973)
at org.apache.qpid.jms.provider.amqp.AmqpProvider.access$1900(AmqpProvider.java:104)
at org.apache.qpid.jms.provider.amqp.AmqpProvider$17.run(AmqpProvider.java:831)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2) testSendMessageWithOptionsAndWithCompletionListener(junitTests.com.fedex.mi.decorator.jms.JmsMessageProducerTests)javax.jms.MessageFormatException: Message must not be null
at org.apache.qpid.jms.JmsSession.send(JmsSession.java:765)
at org.apache.qpid.jms.JmsMessageProducer.sendMessage(JmsMessageProducer.java:246)
at org.apache.qpid.jms.JmsMessageProducer.send(JmsMessageProducer.java:214)
at com.fedex.mi.decorator.jms.FedexJmsMessageProducer.send(FedexJmsMessageProducer.java:488)
at junitTests.com.fedex.mi.decorator.jms.JmsMessageProducerTests.testSendMessageWithOptionsAndWithCompletionListener(JmsMessageProducerTests.java:687)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at junitTests.com.fedex.mi.decorator.jms.FedexJMSJUnitDispatch.runSelectedTests(FedexJMSJUnitDispatch.java:567)
at junitTests.com.fedex.mi.decorator.jms.FedexJMSJUnitDispatch.main(FedexJMSJUnitDispatch.java:709)
For all the issues we've encountered, the client catches an exception, prints out the stack trace, and it doesn't include the client stack info
The exception is thrown from the specific call. I am not sure how internal AMQ works but If AMQ chooses to run the operation in a separate thread, and then do some sort of block waiting for that call to complete before returning the exception in the original client calling thread, that is fine, but it still would be able to build a complete stack trace before handing back control to the calling client thread. Perhaps a new exception with the cause populated by the back ground thread make sense.
Here's another example for connection error with qpid 0.40.0 libs; no client thread info!!
The client code is basically
try
{ Connection con = cf.connect("bad_ID", "bad_pwd"); }catch(Exception e)
{ e.printStackTrace(); }
junitTests.com.fedex.mi.decorator.jms.TestBaseCamp | org.apache.qpid.jms.exceptions.JMSSecuritySaslException: Client failed to authenticate using SASL: PLAIN
at org.apache.qpid.jms.provider.amqp.AmqpSaslAuthenticator.recordFailure(AmqpSaslAuthenticator.java:160)
at org.apache.qpid.jms.provider.amqp.AmqpSaslAuthenticator.handleSaslFail(AmqpSaslAuthenticator.java:138)
at org.apache.qpid.jms.provider.amqp.AmqpSaslAuthenticator.handleSaslOutcome(AmqpSaslAuthenticator.java:109)
at org.apache.qpid.jms.provider.amqp.AmqpProvider$1.onSaslOutcome(AmqpProvider.java:263)
at org.apache.qpid.proton.engine.impl.SaslImpl.handleOutcome(SaslImpl.java:426)
at org.apache.qpid.proton.engine.impl.SaslImpl.handleOutcome(SaslImpl.java:49)
at org.apache.qpid.proton.amqp.security.SaslOutcome.invoke(SaslOutcome.java:75)
at org.apache.qpid.proton.engine.impl.SaslImpl.handle(SaslImpl.java:320)
at org.apache.qpid.proton.engine.impl.SaslFrameParser.input(SaslFrameParser.java:367)
at org.apache.qpid.proton.engine.impl.SaslImpl$SaslTransportWrapper.reallyProcessInput(SaslImpl.java:663)
at org.apache.qpid.proton.engine.impl.SaslImpl$SaslTransportWrapper.process(SaslImpl.java:634)
at org.apache.qpid.proton.engine.impl.SaslImpl$SwitchingSaslTransportWrapper.process(SaslImpl.java:807)
at org.apache.qpid.proton.engine.impl.HandshakeSniffingTransportWrapper.process(HandshakeSniffingTransportWrapper.java:101)
at org.apache.qpid.proton.engine.impl.TransportImpl.process(TransportImpl.java:1540)
at org.apache.qpid.jms.provider.amqp.AmqpProvider.onData(AmqpProvider.java:819)
at org.apache.qpid.jms.transports.netty.NettyTcpTransport$NettyTcpTransportHandler.channelRead0(NettyTcpTransport.java:539)
at org.apache.qpid.jms.transports.netty.NettyTcpTransport$NettyTcpTransportHandler.channelRead0(NettyTcpTransport.java:532)
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:337)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1408)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:930)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:677)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:612)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:529)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:491)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:905)
at java.lang.Thread.run(Unknown Source)
Another example with 0.40.0 qpid libs, that seem to include client stack info correctly.
AMQ119005: error creating consumer, AMQ229200: Maximum Consumer Limit Reached on Queue:(address=topic.sample,queue=UnitTestClientID3456789.MCVDurableSub2) [condition = amqp:internal-error]
at org.apache.qpid.jms.exceptions.JmsExceptionSupport.createRuntimeException(JmsExceptionSupport.java:207)
at org.apache.qpid.jms.JmsContext.unsubscribe(JmsContext.java:157)
at com.fedex.mwa.QpidDurableTest.tryAmqWith(QpidDurableTest.java:128)
at com.fedex.mwa.QpidDurableTest.main(QpidDurableTest.java:140)
Caused by: javax.jms.JMSException: AMQ119005: error creating consumer, AMQ229200: Maximum Consumer Limit Reached on Queue:(address=topic.sample,queue=UnitTestClientID3456789.MCVDurableSub2) [condition = amqp:internal-error]
at org.apache.qpid.jms.provider.amqp.AmqpSupport.convertToException(AmqpSupport.java:167)
at org.apache.qpid.jms.provider.amqp.AmqpSupport.convertToException(AmqpSupport.java:118)
at org.apache.qpid.jms.provider.amqp.builders.AmqpResourceBuilder.handleClosed(AmqpResourceBuilder.java:185)
at org.apache.qpid.jms.provider.amqp.builders.AmqpResourceBuilder.processRemoteClose(AmqpResourceBuilder.java:129)
at org.apache.qpid.jms.provider.amqp.AmqpProvider.processUpdates(AmqpProvider.java:938)
at org.apache.qpid.jms.provider.amqp.AmqpProvider.onData(AmqpProvider.java:824)
at org.apache.qpid.jms.transports.netty.NettyTcpTransport$NettyTcpTransportHandler.channelRead0(NettyTcpTransport.java:539)
at org.apache.qpid.jms.transports.netty.NettyTcpTransport$NettyTcpTransportHandler.channelRead0(NettyTcpTransport.java:532)
at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
Thanks
Ritz