Uploaded image for project: 'Qpid'
  1. Qpid
  2. QPID-6504

[Python Client 0-10] Client can send commands like SessionCompleted, SessionRequestTimeout after sending ConnectionClose

    XMLWordPrintableJSON

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
    • Python Client
    • 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
      

      Attachments

        Activity

          People

            Unassigned Unassigned
            orudyy Alex Rudyy
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated: