[
https://issues.apache.org/jira/browse/QPID-6649?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Keith Wall updated QPID-6649:
-----------------------------
Description:
There is a potential for a race in the Java Broker that is being exposed by the
System Tests. The unlucky case is as follows. The client closes the
connection by sending ConnectionClose. On receiving this,
ServerConnectionDelegate.connectionClose() invokes ServerConnection.setState()
which invokes AbstractVirtualHost.deregisterConnectionAsync(). This causes the
AVH to 'forget' the connection (removed from AVH#_connections) even though it
is not yet closed. Meanwhile, QBTC begins to close the Broker. The Broker
closes the AVH which calls closeConnections - but the connection is already for
forgotten (_connections#size() == 0) so as far as it is concerned there are no
connections to await for, so the VH close concludes and the VHN shutdowns the
VH's executor. Then the IO thread gets scheduled, sends the ConnectionCloseOk
bytes down the wire and then NBC#shutdown invokes MVPE#close.... which finally
invokesServerConnection.setState which calls
AbstractVirtualHost.deregisterConnectionAsync, which fails (stack trace below)
because the task executor is already closed.
This causes a socket to remain open.
{noformat}
015-07-19 17:57:53,998 ERROR [virtualhost-test-iopool-7]
o.a.q.t.u.InternalBrokerHolder Uncaught exception from thread
virtualhost-test-iopool-7
java.lang.IllegalStateException: Task executor is not in ACTIVE state
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.checkState(TaskExecutorImpl.java:310)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.submit(TaskExecutorImpl.java:141)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.doOnConfigThread(AbstractConfiguredObject.java:499)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.setDesiredState(AbstractConfiguredObject.java:1315)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.deleteAsync(AbstractConfiguredObject.java:1837)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.delete(AbstractConfiguredObject.java:1766)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.exchange.AbstractExchange.removeBinding(AbstractExchange.java:666)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.exchange.AbstractExchange.access$000(AbstractExchange.java:80)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.exchange.AbstractExchange$1.stateChanged(AbstractExchange.java:138)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.exchange.AbstractExchange$1.stateChanged(AbstractExchange.java:132)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.binding.BindingImpl.doDelete(BindingImpl.java:208)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[na:1.8.0_45]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[na:1.8.0_45]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[na:1.8.0_45]
at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
at
org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1194)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.attainStateIfOpenedOrReopenFailed(AbstractConfiguredObject.java:1162)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.access$1500(AbstractConfiguredObject.java:83)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$15.call(AbstractConfiguredObject.java:1354)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$15.call(AbstractConfiguredObject.java:1316)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:507)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:500)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.executeTask(TaskExecutorImpl.java:317)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.access$700(TaskExecutorImpl.java:48)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper$1.run(TaskExecutorImpl.java:361)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at java.security.AccessController.doPrivileged(Native Method)
~[na:1.8.0_45]
at javax.security.auth.Subject.doAs(Subject.java:360) ~[na:1.8.0_45]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper.call(TaskExecutorImpl.java:356)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
~[na:1.8.0_45]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
~[na:1.8.0_45]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
~[na:1.8.0_45]
at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_45]
{noformat}
was:
There is a potential for a race in the Java Broker that is being exposed by the
System Tests. The unlucky case is as follows. The client closes the
connection by sending ConnectionClose. On receiving this,
ServerConnectionDelegate.connectionClose() invokes ServerConnection.setState()
which invokes AbstractVirtualHost.deregisterConnectionAsync(). This causes the
AVH to 'forget' the connection (removed from AVH#_connections) even though it
is not yet closed. Meanwhile, QBTC begins to close the Broker. The Broker
closes the AVH which calls closeConnections - but the connection is already for
forgotten (_connections#size() == 0) so as far as it is concerned there are no
connections to await for, so the VH close concludes and the VHN shutdowns the
VH's executor. Then the IO thread gets scheduled, sends the ConnectionCloseOk
bytes down the wire and then NBC#shutdown invokes MVPE#close.... which finally
invokesServerConnection.setState which calls
AbstractVirtualHost.deregisterConnectionAsync, which fails (stack trace from
email earlier today) because the task executor is already closed.
This causes a socket to remain open.
{noformat}
015-07-19 17:57:53,998 ERROR [virtualhost-test-iopool-7]
o.a.q.t.u.InternalBrokerHolder Uncaught exception from thread
virtualhost-test-iopool-7
java.lang.IllegalStateException: Task executor is not in ACTIVE state
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.checkState(TaskExecutorImpl.java:310)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.submit(TaskExecutorImpl.java:141)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.doOnConfigThread(AbstractConfiguredObject.java:499)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.setDesiredState(AbstractConfiguredObject.java:1315)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.deleteAsync(AbstractConfiguredObject.java:1837)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.delete(AbstractConfiguredObject.java:1766)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.exchange.AbstractExchange.removeBinding(AbstractExchange.java:666)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.exchange.AbstractExchange.access$000(AbstractExchange.java:80)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.exchange.AbstractExchange$1.stateChanged(AbstractExchange.java:138)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.exchange.AbstractExchange$1.stateChanged(AbstractExchange.java:132)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
at
org.apache.qpid.server.binding.BindingImpl.doDelete(BindingImpl.java:208)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[na:1.8.0_45]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[na:1.8.0_45]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[na:1.8.0_45]
at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
at
org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1194)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.attainStateIfOpenedOrReopenFailed(AbstractConfiguredObject.java:1162)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject.access$1500(AbstractConfiguredObject.java:83)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$15.call(AbstractConfiguredObject.java:1354)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$15.call(AbstractConfiguredObject.java:1316)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:507)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:500)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.executeTask(TaskExecutorImpl.java:317)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.access$700(TaskExecutorImpl.java:48)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper$1.run(TaskExecutorImpl.java:361)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at java.security.AccessController.doPrivileged(Native Method)
~[na:1.8.0_45]
at javax.security.auth.Subject.doAs(Subject.java:360) ~[na:1.8.0_45]
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper.call(TaskExecutorImpl.java:356)
~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
~[na:1.8.0_45]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
~[na:1.8.0_45]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
~[na:1.8.0_45]
at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_45]
{noformat}
> Client initiated connection close can race with Broker shutdown leading to
> exception and unclosed socket
> --------------------------------------------------------------------------------------------------------
>
> Key: QPID-6649
> URL: https://issues.apache.org/jira/browse/QPID-6649
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker
> Reporter: Keith Wall
> Assignee: Keith Wall
> Fix For: 6.0 [Java]
>
>
> There is a potential for a race in the Java Broker that is being exposed by
> the System Tests. The unlucky case is as follows. The client closes the
> connection by sending ConnectionClose. On receiving this,
> ServerConnectionDelegate.connectionClose() invokes
> ServerConnection.setState() which invokes
> AbstractVirtualHost.deregisterConnectionAsync(). This causes the AVH to
> 'forget' the connection (removed from AVH#_connections) even though it is not
> yet closed. Meanwhile, QBTC begins to close the Broker. The Broker closes
> the AVH which calls closeConnections - but the connection is already for
> forgotten (_connections#size() == 0) so as far as it is concerned there are
> no connections to await for, so the VH close concludes and the VHN shutdowns
> the VH's executor. Then the IO thread gets scheduled, sends the
> ConnectionCloseOk bytes down the wire and then NBC#shutdown invokes
> MVPE#close.... which finally invokesServerConnection.setState which calls
> AbstractVirtualHost.deregisterConnectionAsync, which fails (stack trace
> below) because the task executor is already closed.
> This causes a socket to remain open.
> {noformat}
> 015-07-19 17:57:53,998 ERROR [virtualhost-test-iopool-7]
> o.a.q.t.u.InternalBrokerHolder Uncaught exception from thread
> virtualhost-test-iopool-7
> java.lang.IllegalStateException: Task executor is not in ACTIVE state
> at
> org.apache.qpid.server.configuration.updater.TaskExecutorImpl.checkState(TaskExecutorImpl.java:310)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.configuration.updater.TaskExecutorImpl.submit(TaskExecutorImpl.java:141)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject.doOnConfigThread(AbstractConfiguredObject.java:499)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject.setDesiredState(AbstractConfiguredObject.java:1315)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject.deleteAsync(AbstractConfiguredObject.java:1837)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject.delete(AbstractConfiguredObject.java:1766)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.exchange.AbstractExchange.removeBinding(AbstractExchange.java:666)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
> at
> org.apache.qpid.server.exchange.AbstractExchange.access$000(AbstractExchange.java:80)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
> at
> org.apache.qpid.server.exchange.AbstractExchange$1.stateChanged(AbstractExchange.java:138)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
> at
> org.apache.qpid.server.exchange.AbstractExchange$1.stateChanged(AbstractExchange.java:132)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:na]
> at
> org.apache.qpid.server.binding.BindingImpl.doDelete(BindingImpl.java:208)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> ~[na:1.8.0_45]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> ~[na:1.8.0_45]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> ~[na:1.8.0_45]
> at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1194)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject.attainStateIfOpenedOrReopenFailed(AbstractConfiguredObject.java:1162)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject.access$1500(AbstractConfiguredObject.java:83)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject$15.call(AbstractConfiguredObject.java:1354)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject$15.call(AbstractConfiguredObject.java:1316)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:507)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:500)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.configuration.updater.TaskExecutorImpl.executeTask(TaskExecutorImpl.java:317)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.configuration.updater.TaskExecutorImpl.access$700(TaskExecutorImpl.java:48)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper$1.run(TaskExecutorImpl.java:361)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at java.security.AccessController.doPrivileged(Native Method)
> ~[na:1.8.0_45]
> at javax.security.auth.Subject.doAs(Subject.java:360) ~[na:1.8.0_45]
> at
> org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper.call(TaskExecutorImpl.java:356)
> ~[qpid-broker-core-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> ~[na:1.8.0_45]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> ~[na:1.8.0_45]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> ~[na:1.8.0_45]
> at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_45]
> {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]
