[
https://issues.apache.org/jira/browse/QPIDJMS-467?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Timothy Bish reassigned QPIDJMS-467:
------------------------------------
Assignee: Timothy Bish
> Logging Issue
> -------------
>
> Key: QPIDJMS-467
> URL: https://issues.apache.org/jira/browse/QPIDJMS-467
> Project: Qpid JMS
> Issue Type: Bug
> Components: qpid-jms-client
> Affects Versions: 0.40.0
> Reporter: Ritz
> Assignee: Timothy Bish
> Priority: Minor
> Fix For: 0.40.0
>
>
> 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)
> {color:#FF0000} *at
> junitTests.com.fedex.mi.decorator.jms.JmsMessageProducerTests.testSendMessageWithOptionsAndWithCompletionListener(JmsMessageProducerTests.java:687)*{color}
> 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)
> *{color:#FF0000}at
> com.fedex.mwa.QpidDurableTest.tryAmqWith(QpidDurableTest.java:128){color}*
> {color:#FF0000} *at
> com.fedex.mwa.QpidDurableTest.main(QpidDurableTest.java:140)*{color}
> 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
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org
