You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Alex Rudyy (JIRA)" <ji...@apache.org> on 2016/10/19 15:02:58 UTC
[jira] [Updated] (QPID-6504) [Pthon Client 0-10] Client can send
Test
qpid_tests.broker_0_10.exchange.MiscellaneousErrorsTests.testDefaultAccessUnbind
fails sporadically due to timeout on connection close
[ 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: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org