[
https://issues.apache.org/jira/browse/QPID-6504?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Alex Rudyy updated QPID-6504:
-----------------------------
Description:
Client can send commands like SessionCompleted, SessionRequestTimeout after
sending ConnectionClose
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}
was:
Client can
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}
> [Pthon Client 0-10] Client can send commands like SessionCompleted,
> SessionRequestTimeout after sending ConnectionClose
> -----------------------------------------------------------------------------------------------------------------------
>
> Key: QPID-6504
> URL: https://issues.apache.org/jira/browse/QPID-6504
> Project: Qpid
> Issue Type: Bug
> Components: Python Client
> Affects Versions: 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
> Reporter: Alex Rudyy
>
> Client can send commands like SessionCompleted, SessionRequestTimeout after
> sending ConnectionClose
> 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: [email protected]
For additional commands, e-mail: [email protected]
