You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Keith Wall (JIRA)" <ji...@apache.org> on 2015/03/12 17:32:39 UTC

[jira] [Updated] (QPID-5856) Closing 0-10 messaging connection from management leads to spurious exception and timeout

     [ https://issues.apache.org/jira/browse/QPID-5856?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Keith Wall updated QPID-5856:
-----------------------------
    Fix Version/s: 6.0 [Java]

> Closing 0-10 messaging connection from management leads to spurious exception and timeout
> -----------------------------------------------------------------------------------------
>
>                 Key: QPID-5856
>                 URL: https://issues.apache.org/jira/browse/QPID-5856
>             Project: Qpid
>          Issue Type: Bug
>          Components: Java Broker
>    Affects Versions: 0.22, 0.24, 0.26, 0.28, 0.29
>            Reporter: Keith Wall
>             Fix For: 6.0 [Java]
>
>
> If I close a messaging connection from the REST interface whist the connection is busy, the thread causing the management action hangs for 30 seconds, then I see exception. 
> {noformat}
> qtp1676624311-30 2014-06-27 13:10:43,468 WARN [plugin.servlet.rest.RestServlet] Caught exception
> org.apache.qpid.transport.ConnectionException: close() timed out
>         at org.apache.qpid.transport.Connection.close(Connection.java:657)
>         at org.apache.qpid.transport.Connection.close(Connection.java:630)
>         at org.apache.qpid.server.protocol.v0_10.ServerConnection.close(ServerConnection.java:356)
>         at org.apache.qpid.server.model.adapter.ConnectionAdapter.doDelete(ConnectionAdapter.java:153)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:648)
>         at org.apache.qpid.server.model.AbstractConfiguredObject.attainStateIfResolved(AbstractConfiguredObject.java:628)
>         at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at org.apache.qpid.server.model.AbstractConfiguredObject.automatedSetValue(AbstractConfiguredObject.java:379)
>         at org.apache.qpid.server.model.AbstractConfiguredObject.changeAttribute(AbstractConfiguredObject.java:956)
>         at org.apache.qpid.server.model.AbstractConfiguredObject.changeAttributes(AbstractConfiguredObject.java:1239)
>         at org.apache.qpid.server.model.AbstractConfiguredObject$11.execute(AbstractConfiguredObject.java:1218)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$2.execute(TaskExecutorImpl.java:148)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$2.execute(TaskExecutorImpl.java:144)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.executeTask(TaskExecutorImpl.java:298)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.submit(TaskExecutorImpl.java:130)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.run(TaskExecutorImpl.java:250)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.run(TaskExecutorImpl.java:143)
>         at org.apache.qpid.server.model.AbstractConfiguredObject.runTask(AbstractConfiguredObject.java:1195)
>         at org.apache.qpid.server.model.AbstractConfiguredObject.setAttributes(AbstractConfiguredObject.java:1212)
>         at org.apache.qpid.server.model.AbstractConfiguredObject$7.execute(AbstractConfiguredObject.java:750)
>         at org.apache.qpid.server.model.AbstractConfiguredObject$7.execute(AbstractConfiguredObject.java:735)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.executeTask(TaskExecutorImpl.java:298)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.access$400(TaskExecutorImpl.java:43)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper$1.run(TaskExecutorImpl.java:326)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at javax.security.auth.Subject.doAs(Subject.java:356)
>         at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper.call(TaskExecutorImpl.java:321)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:262)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> {noformat}
> It appears that the Broker continues to try to emit frame after it has sent ConnectionClose and then timing out awaiting the ConnectionCloseOk.  The client is receiving the ConnectionClose, and emitting the ConnectionCloseOk before closing the connection.
> {noformat}
> Broker-Configuration-Thread 2014-06-27 13:08:43,462 DEBUG [apache.qpid.transport.Connection] SEND: [conn:4bd56a3a] ch=0 ConnectionClose(replyCode=CONNECTION_FORCED, replyText=Connection closed by external action)
> Broker-Configuration-Thread 2014-06-27 13:08:43,462 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:4bd56a3a]
> IoReceiver - /127.0.0.1:49997 2014-06-27 13:08:43,462 DEBUG [apache.qpid.transport.Connection] RECV: [conn:4bd56a3a] ch=1 MessageFlow(destination=1, unit=MESSAGE, value=1000)
> IoReceiver - /127.0.0.1:49997 2014-06-27 13:08:43,462 DEBUG [apache.qpid.transport.Session] identify: ch=1, commandId=15
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,462 DEBUG [apache.qpid.transport.Connection] RECV: [conn:33c38a88] ch=0 ConnectionClose(replyCode=CONNECTION_FORCED, replyText=Connection closed by external action)
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,462 DEBUG [apache.qpid.transport.Connection] SEND: [conn:33c38a88] ch=0 ConnectionCloseOk()
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,462 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:33c38a88]
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,463 DEBUG [apache.qpid.transport.Connection] connection closed: conn:33c38a88
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,463 DEBUG [apache.qpid.transport.SessionDelegate] DETACHED: [ssn:"9b9aee4d-a5ec-4831-b850-91eb6e7458ea"]
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,463 DEBUG [apache.qpid.transport.SessionDelegate] DETACHED: [ssn:"d8479447-7f98-4a2c-8863-2280c6f9200d"]
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,463 DEBUG [apache.qpid.jms.FailoverPolicy] All failover methods exhausted
> IoReceiver - /127.0.0.1:49997 2014-06-27 13:08:43,463 DEBUG [apache.qpid.transport.Connection] SEND: [conn:4bd56a3a] ch=1 id=1 ExecutionException(errorCode=NOT_FOUND, commandId=15, description=not-found: destination '1')
> IoReceiver - /127.0.0.1:49997 2014-06-27 13:08:43,463 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:4bd56a3a]
> IoReceiver - localhost/127.0.0.1:15672 2014-06-27 13:08:43,463 ERROR [apache.qpid.client.AMQConnectionDelegate_0_10] connection exception: conn:33c38a88
> {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