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