You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Alex Rudyy (JIRA)" <ji...@apache.org> on 2015/04/21 11:29:02 UTC
[jira] [Created] (QPID-6504) Test
qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind
fails sporadically due to timeout on connection close
Alex Rudyy created QPID-6504:
--------------------------------
Summary: Test qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind fails sporadically due to timeout on connection close
Key: QPID-6504
URL: https://issues.apache.org/jira/browse/QPID-6504
Project: Qpid
Issue Type: Bug
Components: Python Client
Affects Versions: 0.30, 0.28, 0.26, 0.24, 0.22, 0.20, 0.18, 0.16, 0.14, 0.12, 0.10, 0.8, 0.32, 6.0 [Java]
Reporter: Alex Rudyy
The test after receiving an exception in response to unbind command for default exchange verifies the exception error code and proceeds to tearDown where connection is closed. It sends ConnectionClose command and continues receiving and responding sub-sequent commands/controls from the broker. The broker itself after sending an exception to client attempts to close the broker side session by sending SessionRequestTimeout(timeout=0) and SessionDetach. Immediately after that, the Broker receives ConnectionClose and sends ConnectionCloseOk followed by socket close. At the same time client, receives SessionRequestTimeout and attempts to send a response but socket is closed on Broker side. As result, the client does not manage to reply on SessionRequestTimeout and it seems cannot receive ConnectionCloseOK.It looks like the "broken pipe" is reported before client can receive ConnectionCloseOK.
The symptoms described above indicate about client side defect.
Broker logs for the test qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind
{noformat}
2015-04-20 18:21:20,241 INFO [IO-/127.0.0.1:55801] (connection.open) - [con:596(/127.0.0.1:55801)] CON-1001 : Open
2015-04-20 18:21:20,241 INFO [IO-/127.0.0.1:55801] (connection.open) - [con:596(/127.0.0.1:55801)] CON-1001 : Open : Protocol Version : 0-10
2015-04-20 18:21:20,241 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] AMQP.1 0-10
2015-04-20 18:21:20,241 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] AMQP.1 0-10
2015-04-20 18:21:20,241 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=0 ConnectionStart(serverProperties={product=qpid, qpid.build=Unversioned directory, qpid.instance_name=Broker, qpid.message_compression_supported=true, qpid.features=[qpid.jms-selector], qpid.federation_tag=ebf99d76-03f1-43e8-bbeb-a2c4a134ad1c, version=6.0.0-SNAPSHOT}, mechanisms=[PLAIN, CRAM-MD5], locales=[en_US])
2015-04-20 18:21:20,242 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,242 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 321 bytes
2015-04-20 18:21:20,242 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,242 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 0 byte(s)
2015-04-20 18:21:20,242 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,245 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,245 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 217 byte(s)
2015-04-20 18:21:20,246 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=0 ConnectionStartOk(clientProperties={product=qpid python client, qpid.client_version=unidentified, qpid.client_ppid=22599, qpid.client_process=qpid-python-test, platform=posix, qpid.client_pid=10619}, mechanism=PLAIN, response="\x00guest\x00guest")
2015-04-20 18:21:20,246 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=0 ConnectionTune(channelMax=256, maxFrameSize=65535, heartbeatMin=0, heartbeatMax=65535)
2015-04-20 18:21:20,246 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,246 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 24 bytes
2015-04-20 18:21:20,246 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,246 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 0 byte(s)
2015-04-20 18:21:20,247 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,247 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,247 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 16 byte(s)
2015-04-20 18:21:20,248 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=0 ConnectionTuneOk()
2015-04-20 18:21:20,248 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,248 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,248 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 0 byte(s)
2015-04-20 18:21:20,248 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,287 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,287 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 16 byte(s)
2015-04-20 18:21:20,288 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=0 ConnectionOpen()
2015-04-20 18:21:20,288 INFO [IO-/127.0.0.1:55801] (connection.open) - [con:596(guest@/127.0.0.1:55801/default)] CON-1001 : Open : Client ID : null : Protocol Version : 0-10 : Client Version : unidentified : Client Product : qpid python client
2015-04-20 18:21:20,288 DEBUG [IO-/127.0.0.1:55801] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@a9555a9
2015-04-20 18:21:20,288 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@a9555a9
2015-04-20 18:21:20,289 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@a9555a9 is performed successfully with result:null
2015-04-20 18:21:20,289 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=0 ConnectionOpenOk(knownHosts=[])
2015-04-20 18:21:20,290 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,290 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 20 bytes
2015-04-20 18:21:20,290 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,290 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 0 byte(s)
2015-04-20 18:21:20,290 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,312 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,312 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 30 byte(s)
2015-04-20 18:21:20,312 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=1 SessionAttach(name="test-session")
2015-04-20 18:21:20,313 DEBUG [IO-/127.0.0.1:55801] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@78a84f58
2015-04-20 18:21:20,313 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@78a84f58
2015-04-20 18:21:20,314 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@78a84f58 is performed successfully with result:null
2015-04-20 18:21:20,314 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=1 SessionAttached(name="test-session")
2015-04-20 18:21:20,314 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,314 INFO [IO-/127.0.0.1:55801] (channel.create) - [con:596(guest@/127.0.0.1:55801/default)/ch:1] CHN-1001 : Create
2015-04-20 18:21:20,314 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 30 bytes
2015-04-20 18:21:20,314 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,314 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 55 byte(s)
2015-04-20 18:21:20,315 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=1 SessionCommandPoint(commandId=0, commandOffset=0)
2015-04-20 18:21:20,315 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=1 [S] QueueDeclare(queue=my-queue, exclusive=true, autoDelete=true)
2015-04-20 18:21:20,315 DEBUG [IO-/127.0.0.1:55801] (transport.Session) - identify: ch=1, commandId=0
2015-04-20 18:21:20,315 DEBUG [IO-/127.0.0.1:55801] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@1bdb9cb7
2015-04-20 18:21:20,315 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@1bdb9cb7
2015-04-20 18:21:20,316 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@6f0dc0aa
2015-04-20 18:21:20,316 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@6f0dc0aa
2015-04-20 18:21:20,318 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$14@6fe411db
2015-04-20 18:21:20,318 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$14@6fe411db
2015-04-20 18:21:20,318 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$14@6fe411db is performed successfully with result:NEVER
2015-04-20 18:21:20,318 INFO [VirtualHostNode-default-Configuration-Thread] (queue.created) - [con:596(guest@/127.0.0.1:55801/default)/ch:1] [vh(/default)/qu(my-queue)] QUE-1001 : Create : AutoDelete Transient
2015-04-20 18:21:20,319 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@6f0dc0aa is performed successfully with result:null
2015-04-20 18:21:20,321 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@1bdb9cb7 is performed successfully with result:null
2015-04-20 18:21:20,322 DEBUG [IO-/127.0.0.1:55801] (transport.Session) - ssn:"test-session" ch=1 processed([0,0]) -1 -1
2015-04-20 18:21:20,322 DEBUG [IO-/127.0.0.1:55801] (transport.Session) - ssn:"test-session" processed: {}
2015-04-20 18:21:20,322 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=1 SessionCompleted(commands={[0, 0]})
2015-04-20 18:21:20,322 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,322 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 26 bytes
2015-04-20 18:21:20,323 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,323 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 0 byte(s)
2015-04-20 18:21:20,323 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 37 byte(s)
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=1 [S] ExchangeUnbind(queue=my-queue, exchange=, bindingKey=my-queue)
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.Session) - identify: ch=1, commandId=1
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=1 SessionCommandPoint(commandId=0, commandOffset=0)
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=1 id=0 ExecutionException(errorCode=INVALID_ARGUMENT, commandId=1, description=Unbind not allowed for default exchange)
2015-04-20 18:21:20,326 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,327 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=1 SessionFlush(completed=true)
2015-04-20 18:21:20,327 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,327 DEBUG [IO-/127.0.0.1:55801] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@2d8a343a
2015-04-20 18:21:20,327 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@2d8a343a
2015-04-20 18:21:20,328 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@2d8a343a is performed successfully with result:null
2015-04-20 18:21:20,328 DEBUG [IO-/127.0.0.1:55801] (transport.Session) - Closing [ssn:"test-session"] in state [OPEN]
2015-04-20 18:21:20,329 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=1 SessionRequestTimeout(timeout=0)
2015-04-20 18:21:20,329 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,329 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=1 SessionDetach(name="test-session")
2015-04-20 18:21:20,329 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,329 DEBUG [IO-/127.0.0.1:55801] (transport.Session) - ssn:"test-session" ch=1 processed([1,1]) 0 0
2015-04-20 18:21:20,329 DEBUG [IO-/127.0.0.1:55801] (transport.Session) - ssn:"test-session" processed: {[0, 0]}
2015-04-20 18:21:20,329 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 159 bytes
2015-04-20 18:21:20,330 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,330 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 0 byte(s)
2015-04-20 18:21:20,330 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,333 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,333 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Read 18 byte(s)
2015-04-20 18:21:20,333 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - RECV: [conn:17945207] ch=0 ConnectionClose(replyCode=NORMAL)
2015-04-20 18:21:20,333 INFO [IO-/127.0.0.1:55801] (connection.close) - [con:596(guest@/127.0.0.1:55801/default)] [con:596(/127.0.0.1:55801)] CON-1002 : Close
2015-04-20 18:21:20,333 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - SEND: [conn:17945207] ch=0 ConnectionCloseOk()
2015-04-20 18:21:20,333 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - FLUSH: [conn:17945207]
2015-04-20 18:21:20,333 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Closing /127.0.0.1:55801
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 16 bytes
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Written 0 bytes
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Closing receiver
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (protocol.MultiVersionProtocolEngine) - Closed
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@4c6ae331
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (transport.Connection) - connection closed: conn:17945207
2015-04-20 18:21:20,334 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@4c6ae331
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@7d69cd28
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (txn.LocalTransaction) - Beginning 0 post transaction actions
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (txn.LocalTransaction) - Completed post transaction actions
2015-04-20 18:21:20,334 DEBUG [IO-/127.0.0.1:55801] (updater.TaskExecutorImpl) - Submitting task: org.apache.qpid.server.model.AbstractConfiguredObject$2@2d1c3d6b
2015-04-20 18:21:20,334 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@4c6ae331 is performed successfully with result:null
2015-04-20 18:21:20,334 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@7d69cd28
2015-04-20 18:21:20,334 INFO [IO-/127.0.0.1:55801] (queue.deleted) - [Broker] [vh(/default)/qu(my-queue)] QUE-1002 : Deleted
2015-04-20 18:21:20,335 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@7d69cd28 is performed successfully with result:null
2015-04-20 18:21:20,335 INFO [IO-/127.0.0.1:55801] (channel.close_forced) - [Broker] [con:596(null@/127.0.0.1:55801/default)/ch:1] CHN-1003 : Close : 542 - Unbind not allowed for default exchange
2015-04-20 18:21:20,335 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Performing task org.apache.qpid.server.model.AbstractConfiguredObject$2@2d1c3d6b
2015-04-20 18:21:20,335 DEBUG [IO-/127.0.0.1:55801] (transport.NonBlockingConnection) - Closing /127.0.0.1:55801
2015-04-20 18:21:20,335 DEBUG [VirtualHostNode-default-Configuration-Thread] (model.AbstractConfiguredObject) - Closing StandardQueueImpl : my-queue
2015-04-20 18:21:20,335 DEBUG [VirtualHostNode-default-Configuration-Thread] (model.AbstractConfiguredObject) - All children closed StandardQueueImpl : my-queue
2015-04-20 18:21:20,335 DEBUG [VirtualHostNode-default-Configuration-Thread] (model.AbstractConfiguredObject) - Closed StandardQueueImpl : my-queue
2015-04-20 18:21:20,335 DEBUG [VirtualHostNode-default-Configuration-Thread] (updater.TaskExecutorImpl) - Task org.apache.qpid.server.model.AbstractConfiguredObject$2@2d1c3d6b is performed successfully with result:null
{noformat}
Client logs for the test qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind
{noformat}
qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind .............................................................. start
2015-04-20 18:21:20,240 DEBUG SENT 'AMQP\x01\x01\x00\n'
2015-04-20 18:21:20,240 DEBUG FLUSHED
2015-04-20 18:21:20,242 DEBUG RECV 'AMQP\x01\x01\x00\n'
2015-04-20 18:21:20,244 DEBUG RECV ConnectionStart(server_properties={u'qpid.message_compression_supported': u'true', u'product': u'qpid', u'qpid.instance_name': u'Broker', u'qpid.build': u'Unversioned directory', u'version': u'6.0.0-SNAPSHOT', u'qpid.features': [u'qpid.jms-selector'], u'qpid.federation_tag': u'ebf99d76-03f1-43e8-bbeb-a2c4a134ad1c'}, mechanisms=[u'PLAIN', u'CRAM-MD5'], locales=[u'en_US'])
2015-04-20 18:21:20,245 DEBUG SENT '\x0f\x00\x00\xd9\x00\x00\x00\x00\x00\x00\x00\x00\x01\x02\x07\x00\x00\x00\x00\xaf\x00\x00\x00\x06\x07product\x95\x00\x12qpid python client\x13qpid.client_version\x95\x00\x0cunidentified\x10qpid.client_ppid1\x00\x00\x00\x00\x00\x00XG\x13qpid.client_process\x95\x00\x10qpid-python-test\x08platform\x95\x00\x05posix\x0fqpid.client_pid1\x00\x00\x00\x00\x00\x00){\x05PLAIN\x00\x00\x00\x0c\x00guest\x00guest'
2015-04-20 18:21:20,246 DEBUG FLUSHED
2015-04-20 18:21:20,246 DEBUG SENT ConnectionStartOk(client_properties={'product': 'qpid python client', 'qpid.client_version': 'unidentified', 'qpid.client_ppid': 22599, 'qpid.client_process': 'qpid-python-test', 'platform': 'posix', 'qpid.client_pid': 10619}, mechanism='PLAIN', response='\x00guest\x00guest')
2015-04-20 18:21:20,247 DEBUG RECV ConnectionTune(channel_max=256, max_frame_size=65535, heartbeat_min=0, heartbeat_max=65535)
2015-04-20 18:21:20,247 DEBUG SENT '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\x06\x00\x00'
2015-04-20 18:21:20,248 DEBUG FLUSHED
2015-04-20 18:21:20,248 DEBUG SENT ConnectionTuneOk()
2015-04-20 18:21:20,248 DEBUG SENT '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\x07\x00\x00'
2015-04-20 18:21:20,249 DEBUG FLUSHED
2015-04-20 18:21:20,249 DEBUG SENT ConnectionOpen()
2015-04-20 18:21:20,290 DEBUG RECV ConnectionOpenOk()
2015-04-20 18:21:20,310 DEBUG SENT '\x0f\x00\x00\x1e\x00\x00\x00\x01\x00\x00\x00\x00\x02\x01\x01\x00\x00\x0ctest-session'
2015-04-20 18:21:20,310 DEBUG FLUSHED
2015-04-20 18:21:20,310 DEBUG SENT SessionAttach(name='test-session', channel=1)
2015-04-20 18:21:20,311 DEBUG SENT '\x0f\x00\x00\x1c\x00\x00\x00\x01\x00\x00\x00\x00\x02\x07\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
2015-04-20 18:21:20,311 DEBUG FLUSHED
2015-04-20 18:21:20,311 DEBUG SENT SessionCommandPoint(command_id=serial(0), command_offset=0, channel=1)
2015-04-20 18:21:20,312 DEBUG SENT '\x0f\x01\x00\x1b\x00\x01\x00\x01\x00\x00\x00\x00\x08\x01\x01\x011\x00\x08my-queue'
2015-04-20 18:21:20,312 DEBUG FLUSHED
2015-04-20 18:21:20,312 DEBUG SENT QueueDeclare(queue='my-queue', exclusive=True, auto_delete=True, channel=1, id=serial(0), sync=True)
2015-04-20 18:21:20,315 DEBUG RECV SessionAttached(name='test-session', channel=1)
2015-04-20 18:21:20,323 DEBUG RECV SessionCompleted(commands=[0-0], channel=1)
2015-04-20 18:21:20,326 DEBUG SENT '\x0f\x01\x00%\x00\x01\x00\x01\x00\x00\x00\x00\x07\x05\x01\x01\x07\x00\x08my-queue\x00\x08my-queue'
2015-04-20 18:21:20,331 DEBUG RECV SessionCommandPoint(command_id=serial(0), command_offset=0, channel=1)
2015-04-20 18:21:20,331 DEBUG FLUSHED
2015-04-20 18:21:20,331 DEBUG RECV ExecutionException(error_code=542, command_id=serial(1), description=u'Unbind not allowed for default exchange', channel=1, id=serial(0))
2015-04-20 18:21:20,332 DEBUG SENT ExchangeUnbind(queue='my-queue', exchange='', binding_key='my-queue', channel=1, id=serial(1), sync=True)
2015-04-20 18:21:20,332 DEBUG RECV SessionFlush(completed=True, channel=1)
2015-04-20 18:21:20,333 DEBUG SENT '\x0f\x00\x00\x12\x00\x00\x00\x00\x00\x00\x00\x00\x01\x0b\x01\x00\x00\xc8'
2015-04-20 18:21:20,335 DEBUG FLUSHED
2015-04-20 18:21:20,336 DEBUG SENT ConnectionClose(reply_code=200)
2015-04-20 18:21:20,336 DEBUG SENT '\x0f\x00\x00\x1a\x00\x00\x00\x01\x00\x00\x00\x00\x02\n\x01\x00\x00\x08\x00\x00\x00\x00\x00\x00\x00\x00'
2015-04-20 18:21:20,336 DEBUG FLUSHED
2015-04-20 18:21:20,336 DEBUG SENT SessionCompleted(commands=[0-0], channel=1)
2015-04-20 18:21:20,337 DEBUG RECV SessionRequestTimeout(timeout=0, channel=1)
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib64/python2.7/threading.py", line 811, in __bootstrap_inner
self.run()
File "/usr/lib64/python2.7/threading.py", line 764, in run
self.__target(*self.__args, **self.__kwargs)
File "/home/alex/workspace/qpid/qpid/python/qpid/connection.py", line 197, in run
self.delegate.received(op)
File "/home/alex/workspace/qpid/qpid/python/qpid/delegates.py", line 46, in received
getattr(self, op.NAME)(ch, op)
File "/home/alex/workspace/qpid/qpid/python/qpid/delegates.py", line 90, in session_request_timeout
ch.session_timeout(rt.timeout);
File "/home/alex/workspace/qpid/qpid/python/qpid/generator.py", line 25, in <lambda>
method = lambda self, *args, **kwargs: self.invoke(op, args, kwargs)
File "/home/alex/workspace/qpid/qpid/python/qpid/connection.py", line 243, in invoke
self.connection.write_op(ctl)
File "/home/alex/workspace/qpid/qpid/python/qpid/connection.py", line 214, in write_op
self.flush()
File "/home/alex/workspace/qpid/qpid/python/qpid/framer.py", line 58, in flush
self._write(cipher_buf)
File "/home/alex/workspace/qpid/qpid/python/qpid/framer.py", line 69, in _write
n = self.sock.send(buf)
error: [Errno 32] Broken pipe
qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind .............................................................. fail
Error during teardown: Traceback (most recent call last):
File "./qpid-python-test", line 340, in run
phase()
File "/home/alex/workspace/qpid/qpid/tests/src/py/qpid_tests/broker_0_10/exchange.py", line 51, in tearDown
TestBase010.tearDown(self)
File "/home/alex/workspace/qpid/qpid/python/qpid/testlib.py", line 232, in tearDown
self.conn.close(timeout=10)
File "/home/alex/workspace/qpid/qpid/python/qpid/connection.py", line 222, in close
raise Timeout()
Timeout
Totals: 135 tests, 0 passed, 0 skipped, 134 ignored, 1 failed
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org