Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
0.8, 0.10, 0.12, 0.14, 0.16, 0.18, 0.20, 0.22, 0.24, 0.26, 0.28, 0.30, 0.32, qpid-java-6.0
-
None
-
None
Description
Client can send commands like SessionCompleted, SessionRequestTimeout after sending ConnectionClose
Broker logs for the test qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind
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
Client logs for the test qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind
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