[ 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