pmoravec
commented
11 years ago When running provided Spout utilizing new client implementation, the init cause / broker exception text is missing there as well:
$ java org.apache.qpid.amqp_0_10.example.Spout -u "amqp://username:password@clientid/test?brokerlist='tcp://localhost:5672'" -c=100000 --content="aaaaaaaaaaaaaaaaaaaaaaaaaaa" "DurableQueue; {create:always, node:{durable:true, x-declare:{ arguments:{'qpid.file_size':10, 'qpid.file_count':4 }}}}"
{content=aaaaaaaaaaaaaaaaaaaaaaaaaaa, u=amqp://username:password@clientid/test?brokerlist='tcp://localhost:5672', c=100000}
main 2013-09-03 14:08:00,445 DEBUG [amqp_0_10.jms.impl.ConnectionImpl] Attempting connection to host: localhost port: 5672 vhost: null username: guest
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,520 DEBUG [apache.qpid.common.QpidProperties] Dumping QpidProperties
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,520 DEBUG [apache.qpid.common.QpidProperties] Property: qpid.version Value: 0.23
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,520 DEBUG [apache.qpid.common.QpidProperties] Property: qpid.svnversion Value: exported
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,520 DEBUG [apache.qpid.common.QpidProperties] Property: qpid.name Value: qpid
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,520 DEBUG [apache.qpid.common.QpidProperties] End of property dump
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,527 DEBUG [qpid.client.security.DynamicSaslRegistrar] public static void registerSaslProviders(): called
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,529 DEBUG [qpid.client.security.DynamicSaslRegistrar] props = {ANONYMOUS=org.apache.qpid.client.security.anonymous.AnonymousSaslClientFactory, CRAM-MD5-HASHED=org.apache.qpid.client.security.crammd5hashed.CRAMMD5HashedSaslClientFactory, AMQPLAIN=org.apache.qpid.client.security.amqplain.AmqPlainSaslClientFactory}
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,530 DEBUG [qpid.client.security.DynamicSaslRegistrar] Found class org.apache.qpid.client.security.anonymous.AnonymousSaslClientFactory for mechanism ANONYMOUS
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,530 DEBUG [qpid.client.security.DynamicSaslRegistrar] Found class org.apache.qpid.client.security.crammd5hashed.CRAMMD5HashedSaslClientFactory for mechanism CRAM-MD5-HASHED
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,531 DEBUG [qpid.client.security.DynamicSaslRegistrar] Found class org.apache.qpid.client.security.amqplain.AmqPlainSaslClientFactory for mechanism AMQPLAIN
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,531 DEBUG [qpid.client.security.JCAProvider] Recording SASL Client factory for AMQPLAIN as org.apache.qpid.client.security.amqplain.AmqPlainSaslClientFactory
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,531 DEBUG [qpid.client.security.JCAProvider] Recording SASL Client factory for ANONYMOUS as org.apache.qpid.client.security.anonymous.AnonymousSaslClientFactory
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,531 DEBUG [qpid.client.security.JCAProvider] Recording SASL Client factory for CRAM-MD5-HASHED as org.apache.qpid.client.security.crammd5hashed.CRAMMD5HashedSaslClientFactory
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,540 INFO [qpid.client.security.DynamicSaslRegistrar] Additional SASL providers successfully registered.
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:00,542 INFO [qpid.client.security.CallbackHandlerRegistry] Callback handlers available for SASL mechanisms: [EXTERNAL, GSSAPI, CRAM-MD5-HASHED, CRAM-MD5, AMQPLAIN, PLAIN, ANONYMOUS]
main 2013-09-03 14:08:00,550 DEBUG [amqp_0_10.jms.impl.ConnectionImpl] Successfully connected to host : localhost port: 5672
main 2013-09-03 14:08:00,550 WARN [jms.impl.failover.FailoverManagerImpl] Initial Connection Attempt Successfull
main 2013-09-03 14:08:00,566 DEBUG [apache.qpid.address.DestSyntax] Based on DurableQueue; {create:always, node:{durable:true, x-declare:{ arguments:{'qpid.file_size':10, 'qpid.file_count':4 }}}} the selected destination syntax is ADDR
main 2013-09-03 14:08:00,586 DEBUG [amqp_0_10.jms.impl.MessageProducerImpl] Sucessfully created message producer for : 'DurableQueue'/None; org.apache.qpid.address.Node@54acb158 org.apache.qpid.address.Link@15af33d6
Sent 0 messages
Sent 1 messages
..
Sent 7777 messages
IoSender - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.503 2013-09-03 14:08:02,361 ERROR [transport.network.io.IoSender] error in write thread
java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:321)
at java.lang.Thread.run(Thread.java:679)
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:02,363 WARN [transport.network.io.IoReceiver] Exception in IoReceiver
org.apache.qpid.transport.SenderException: java.net.SocketException: Connection reset
at org.apache.qpid.transport.network.io.IoSender.close(IoSender.java:242)
at org.apache.qpid.transport.network.io.IoSender.close(IoSender.java:202)
at org.apache.qpid.transport.network.Disassembler.close(Disassembler.java:87)
at org.apache.qpid.transport.ConnectionDelegate.sendConnectionCloseOkAndCloseSender(ConnectionDelegate.java:82)
at org.apache.qpid.transport.ConnectionDelegate.connectionClose(ConnectionDelegate.java:74)
at org.apache.qpid.transport.ConnectionDelegate.connectionClose(ConnectionDelegate.java:1)
at org.apache.qpid.transport.ConnectionClose.dispatch(ConnectionClose.java:90)
at org.apache.qpid.transport.ConnectionDelegate.control(ConnectionDelegate.java:49)
at org.apache.qpid.transport.ConnectionDelegate.control(ConnectionDelegate.java:1)
at org.apache.qpid.transport.Method.delegate(Method.java:163)
at org.apache.qpid.transport.Connection.received(Connection.java:393)
at org.apache.qpid.transport.Connection.received(Connection.java:1)
at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:97)
at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:183)
at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:131)
at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
at org.apache.qpid.transport.network.Assembler.received(Assembler.java:102)
at org.apache.qpid.transport.network.Assembler.received(Assembler.java:1)
at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:189)
at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:105)
at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:1)
at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:168)
at java.lang.Thread.run(Thread.java:679)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:321)
... 1 more
IoReceiver - localhost/127.0.0.1:5672 -2013-09-03 14:08:00.500 2013-09-03 14:08:02,364 ERROR [amqp_0_10.jms.impl.ConnectionImpl] Connection exception received!
Exception in thread "main" org.apache.qpid.amqp_0_10.jms.ConnectionFailedException: Error sending message
at org.apache.qpid.util.ExceptionHelper.toJMSException(ExceptionHelper.java:43)
at org.apache.qpid.amqp_0_10.jms.impl.MessageProducerImpl.sendImpl(MessageProducerImpl.java:336)
at org.apache.qpid.amqp_0_10.jms.impl.MessageProducerImpl.send(MessageProducerImpl.java:202)
at org.apache.qpid.amqp_0_10.example.Spout.
When broker responds with an exception (like enqueue capacity threshold reached), the library does not put the cause as initial cause to the exception raised. Rather, two different types of exception are raised.
Reproducer:
java org.apache.qpid.example.Spout -c=100000 --content="aaaaaaaaaaaaaaaaaaaaaaaaaaa" "DurableQueue; {create:always, node:{durable:true, x-declare:{ arguments:{'qpid.file_size':10, 'qpid.file_count':4 }}}}"
Exception in thread "main" javax.jms.JMSException: Exception when sending message:Command was interrupted because of failover, before being sent at org.apache.qpid.client.BasicMessageProducer_0_10.sendMessage(BasicMessageProducer_0_10.java:243) at org.apache.qpid.client.BasicMessageProducer.sendImpl(BasicMessageProducer.java:500) at org.apache.qpid.client.BasicMessageProducer.send(BasicMessageProducer.java:298) at org.apache.qpid.example.Spout.(Spout.java:98)
at org.apache.qpid.example.Spout.main(Spout.java:152)
Caused by: org.apache.qpid.transport.SessionException: Command was interrupted because of failover, before being sent
at org.apache.qpid.transport.Session.checkFailoverRequired(Session.java:835)
at org.apache.qpid.transport.Session.invoke(Session.java:667)
at org.apache.qpid.transport.Session.invoke(Session.java:636)
at org.apache.qpid.transport.SessionInvoker.messageTransfer(SessionInvoker.java:93)
at org.apache.qpid.client.BasicMessageProducer_0_10.sendMessage(BasicMessageProducer_0_10.java:229)
... 4 more
or sometimes (non-deterministic behaviour):
Exception in thread "main" javax.jms.JMSException: Exception when sending message:connection aborted at org.apache.qpid.client.BasicMessageProducer_0_10.sendMessage(BasicMessageProducer_0_10.java:243) at org.apache.qpid.client.BasicMessageProducer.sendImpl(BasicMessageProducer.java:500) at org.apache.qpid.client.BasicMessageProducer.send(BasicMessageProducer.java:298) at org.apache.qpid.example.Spout.(Spout.java:98)
at org.apache.qpid.example.Spout.main(Spout.java:152)
Caused by: org.apache.qpid.transport.TransportFailureException: connection aborted
at org.apache.qpid.transport.network.io.IoSender.send(IoSender.java:118)
at org.apache.qpid.transport.network.io.IoSender.send(IoSender.java:43)
at org.apache.qpid.transport.network.Disassembler.frame(Disassembler.java:117)
at org.apache.qpid.transport.network.Disassembler.fragment(Disassembler.java:147)
at org.apache.qpid.transport.network.Disassembler.method(Disassembler.java:233)
at org.apache.qpid.transport.network.Disassembler.command(Disassembler.java:172)
at org.apache.qpid.transport.network.Disassembler.command(Disassembler.java:48)
at org.apache.qpid.transport.Method.delegate(Method.java:159)
at org.apache.qpid.transport.network.Disassembler.send(Disassembler.java:73)
at org.apache.qpid.transport.network.Disassembler.send(Disassembler.java:48)
at org.apache.qpid.transport.Connection.send(Connection.java:402)
at org.apache.qpid.transport.Session.send(Session.java:611)
at org.apache.qpid.transport.Session.invoke(Session.java:781)
at org.apache.qpid.transport.Session.invoke(Session.java:636)
at org.apache.qpid.transport.SessionInvoker.messageTransfer(SessionInvoker.java:93)
at org.apache.qpid.client.BasicMessageProducer_0_10.sendMessage(BasicMessageProducer_0_10.java:229)
... 4 more
Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:321)
at java.lang.Thread.run(Thread.java:679)
(while the broker complains "Enqueue capacity threshold exceeded on queue "DurableQueue".")
Alternative reproducer:
java org.apache.qpid.example.Spout -c=100000 --content="aaaaaaaaaaaaaaaaaaaaaaaaaaa" "DurableQueue; {create:always, node:{durable:true, x-declare:{ arguments:{'qpid.file_size':10, 'qpid.file_count':2 }}}}"
Exception in thread "main" javax.jms.JMSException: Error creating producer at org.apache.qpid.client.AMQSession.toJMSException(AMQSession.java:3468) at org.apache.qpid.client.AMQSession_0_10.createMessageProducer(AMQSession_0_10.java:694) at org.apache.qpid.client.AMQSession_0_10.createMessageProducer(AMQSession_0_10.java:88) at org.apache.qpid.client.AMQSession$7.execute(AMQSession.java:2593) at org.apache.qpid.client.AMQSession$7.execute(AMQSession.java:2584) at org.apache.qpid.client.AMQConnectionDelegate_0_10.executeRetrySupport(AMQConnectionDelegate_0_10.java:371) at org.apache.qpid.client.AMQConnection.executeRetrySupport(AMQConnection.java:624) at org.apache.qpid.client.failover.FailoverRetrySupport.execute(FailoverRetrySupport.java:102) at org.apache.qpid.client.AMQSession.createProducerImpl(AMQSession.java:2582) at org.apache.qpid.client.AMQSession.createProducer(AMQSession.java:1164) at org.apache.qpid.client.AMQSession.createProducer(AMQSession.java:98) at org.apache.qpid.example.Spout.(Spout.java:91)
at org.apache.qpid.example.Spout.main(Spout.java:152)
Caused by: org.apache.qpid.AMQException: Exception occured while verifying destination
at org.apache.qpid.client.BasicMessageProducer_0_10.declareDestination(BasicMessageProducer_0_10.java:95)
at org.apache.qpid.client.BasicMessageProducer.(BasicMessageProducer.java:136)
at org.apache.qpid.client.BasicMessageProducer_0_10.(BasicMessageProducer_0_10.java:64)
at org.apache.qpid.client.AMQSession_0_10.createMessageProducer(AMQSession_0_10.java:689)
... 11 more
Caused by: org.apache.qpid.AMQException: Session sync was interrupted by failover. [error code 541: internal error]
at org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1070)
at org.apache.qpid.client.AMQSession_0_10.sync(AMQSession_0_10.java:1050)
at org.apache.qpid.client.AMQSession_0_10.handleQueueNodeCreation(AMQSession_0_10.java:1476)
at org.apache.qpid.client.AMQSession_0_10.resolveAddress(AMQSession_0_10.java:1233)
at org.apache.qpid.client.BasicMessageProducer_0_10.declareDestination(BasicMessageProducer_0_10.java:89)
... 14 more
(while the broker complains "Parameter qpid.file_count: Illegal number of store journal files (2), must be 4 to 64 inclusive.")