Ritz created QPIDJMS-467:
----------------------------
Summary: 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
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.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
