Timothy Bish created AMQ-6291:
---------------------------------
Summary: Thread unsafe code in TcpTransportServer can lead to NPE
or other errors on start / stop
Key: AMQ-6291
URL: https://issues.apache.org/jira/browse/AMQ-6291
Project: ActiveMQ
Issue Type: Bug
Components: Broker, Transport
Affects Versions: 5.13.3, 5.13.2, 5.12.3, 5.13.1, 5.12.2, 5.13.0
Reporter: Timothy Bish
Assignee: Timothy Bish
Fix For: 5.14.0, 5.13.4
Access to several variable in TcpTransportServer is done in an unsafe manner
which can lead to NPE or other data race exceptions on start or stop, one
example below:
{noformat}
Error Message
got: <false>, expected: is <true>
Stacktrace
org.junit.AssumptionViolatedException: got: <false>, expected: is <true>
at org.junit.Assume.assumeThat(Assume.java:95)
at org.junit.Assume.assumeTrue(Assume.java:41)
at
org.apache.activemq.transport.stomp.StompMaxFrameSizeTest.testOversizedActionOnNioSocket(StompMaxFrameSizeTest.java:184)
Standard Output
2016-05-11 23:32:34,331 [main ] - INFO StompTestSupport
- ========== start testOversizedActionOnNioSocket[0] ==========
2016-05-11 23:32:34,339 [main ] - DEBUG StompTestSupport
- Using stomp port 38198
2016-05-11 23:32:34,345 [main ] - DEBUG StompTestSupport
- Using stomp+ssl port 54202
2016-05-11 23:32:34,346 [main ] - DEBUG StompTestSupport
- Using stomp+nio port 56816
2016-05-11 23:32:34,350 [main ] - DEBUG StompTestSupport
- Using stomp+nio+ssl port 50013
2016-05-11 23:32:34,353 [main ] - WARN BrokerService
- Memory Usage for the Broker (1024mb) is more than the maximum available for
the JVM: 891 mb - resetting to 70% of maximum available: 623 mb
2016-05-11 23:32:34,365 [main ] - INFO BrokerService
- Using Persistence Adapter: MemoryPersistenceAdapter
2016-05-11 23:32:34,370 [main ] - INFO BrokerService
- Apache ActiveMQ 5.14.0-SNAPSHOT (localhost,
ID:jenkins-test-39e-56729-1463009553425-0:4) is starting
2016-05-11 23:32:34,374 [main ] - INFO TransportServerThreadSupport
- Listening for connections at:
stomp://jenkins-test-39e:38198?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
2016-05-11 23:32:34,374 [main ] - INFO TransportConnector
- Connector
stomp://jenkins-test-39e:38198?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
started
2016-05-11 23:32:34,375 [main ] - INFO TransportServerThreadSupport
- Listening for connections at:
stomp+ssl://jenkins-test-39e:54202?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
2016-05-11 23:32:34,376 [main ] - INFO TransportConnector
- Connector
stomp+ssl://jenkins-test-39e:54202?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
started
2016-05-11 23:32:34,377 [main ] - INFO TransportServerThreadSupport
- Listening for connections at:
stomp+nio://jenkins-test-39e:56816?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
2016-05-11 23:32:34,377 [main ] - INFO TransportConnector
- Connector
stomp+nio://jenkins-test-39e:56816?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
started
2016-05-11 23:32:34,379 [main ] - INFO TransportServerThreadSupport
- Listening for connections at:
stomp+nio+ssl://jenkins-test-39e:50013?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
2016-05-11 23:32:34,379 [main ] - INFO TransportConnector
- Connector
stomp+nio+ssl://jenkins-test-39e:50013?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
started
2016-05-11 23:32:34,380 [main ] - INFO BrokerService
- Apache ActiveMQ 5.14.0-SNAPSHOT (localhost,
ID:jenkins-test-39e-56729-1463009553425-0:4) started
2016-05-11 23:32:34,380 [main ] - INFO BrokerService
- For help or more information please see: http://activemq.apache.org
2016-05-11 23:32:34,380 [main ] - WARN BrokerService
- Temporary Store limit is 51200 mb (current store usage is 0 mb). The data
directory:
/home/jenkins/jenkins-slave/workspace/ActiveMQ-Java7/activemq-stomp/target only
has 14884 mb of usable space. - resetting to maximum available disk space:
14884 mb
2016-05-11 23:32:34,381 [main ] - INFO BrokerService
- Apache ActiveMQ 5.14.0-SNAPSHOT (localhost,
ID:jenkins-test-39e-56729-1463009553425-0:4) is shutting down
2016-05-11 23:32:34,381 [main ] - INFO TransportConnector
- Connector
stomp://jenkins-test-39e:38198?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
stopped
2016-05-11 23:32:34,382 [main ] - INFO TransportConnector
- Connector
stomp+ssl://jenkins-test-39e:54202?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
stopped
2016-05-11 23:32:34,383 [main ] - ERROR StompNIOTransportFactory$1
- Could not stop service:
stomp+nio://0.0.0.0:0?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536.
Reason: java.lang.NullPointerException
java.lang.NullPointerException
at
java.nio.channels.spi.AbstractSelectableChannel.removeKey(AbstractSelectableChannel.java:128)
at
java.nio.channels.spi.AbstractSelector.deregister(AbstractSelector.java:185)
at sun.nio.ch.EPollSelectorImpl.implClose(EPollSelectorImpl.java:147)
at sun.nio.ch.SelectorImpl.implCloseSelector(SelectorImpl.java:114)
at
java.nio.channels.spi.AbstractSelector.close(AbstractSelector.java:108)
at
org.apache.activemq.transport.tcp.TcpTransportServer.doStop(TcpTransportServer.java:476)
at org.apache.activemq.util.ServiceSupport.stop(ServiceSupport.java:71)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.TransportConnector.stop(TransportConnector.java:283)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.BrokerService.stopAllConnectors(BrokerService.java:2208)
at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:819)
at
org.apache.activemq.transport.stomp.StompTestSupport.stopBroker(StompTestSupport.java:177)
at
org.apache.activemq.transport.stomp.StompTestSupport.tearDown(StompTestSupport.java:116)
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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.junit.runners.Suite.runChild(Suite.java:128)
at org.junit.runners.Suite.runChild(Suite.java:27)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
at
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
at
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
at
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
at
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
2016-05-11 23:32:34,385 [main ] - ERROR StompNIOTransportFactory$1
- Could not stop service:
stomp+nio://0.0.0.0:0?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536.
Reason: java.lang.NullPointerException
java.lang.NullPointerException
at
java.nio.channels.spi.AbstractSelectableChannel.removeKey(AbstractSelectableChannel.java:128)
at
java.nio.channels.spi.AbstractSelector.deregister(AbstractSelector.java:185)
at sun.nio.ch.EPollSelectorImpl.implClose(EPollSelectorImpl.java:147)
at sun.nio.ch.SelectorImpl.implCloseSelector(SelectorImpl.java:114)
at
java.nio.channels.spi.AbstractSelector.close(AbstractSelector.java:108)
at
org.apache.activemq.transport.tcp.TcpTransportServer.doStop(TcpTransportServer.java:476)
at org.apache.activemq.util.ServiceSupport.stop(ServiceSupport.java:71)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.TransportConnector.stop(TransportConnector.java:283)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.BrokerService.stopAllConnectors(BrokerService.java:2208)
at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:819)
at
org.apache.activemq.transport.stomp.StompTestSupport.stopBroker(StompTestSupport.java:177)
at
org.apache.activemq.transport.stomp.StompTestSupport.tearDown(StompTestSupport.java:116)
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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.junit.runners.Suite.runChild(Suite.java:128)
at org.junit.runners.Suite.runChild(Suite.java:27)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
at
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
at
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
at
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
at
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
2016-05-11 23:32:34,386 [main ] - ERROR ManagedTransportConnector
- Could not stop service:
stomp+nio://jenkins-test-39e:56816?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536.
Reason: java.lang.NullPointerException
java.lang.NullPointerException
at
java.nio.channels.spi.AbstractSelectableChannel.removeKey(AbstractSelectableChannel.java:128)
at
java.nio.channels.spi.AbstractSelector.deregister(AbstractSelector.java:185)
at sun.nio.ch.EPollSelectorImpl.implClose(EPollSelectorImpl.java:147)
at sun.nio.ch.SelectorImpl.implCloseSelector(SelectorImpl.java:114)
at
java.nio.channels.spi.AbstractSelector.close(AbstractSelector.java:108)
at
org.apache.activemq.transport.tcp.TcpTransportServer.doStop(TcpTransportServer.java:476)
at org.apache.activemq.util.ServiceSupport.stop(ServiceSupport.java:71)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.TransportConnector.stop(TransportConnector.java:283)
at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
at
org.apache.activemq.broker.BrokerService.stopAllConnectors(BrokerService.java:2208)
at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:819)
at
org.apache.activemq.transport.stomp.StompTestSupport.stopBroker(StompTestSupport.java:177)
at
org.apache.activemq.transport.stomp.StompTestSupport.tearDown(StompTestSupport.java:116)
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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.junit.runners.Suite.runChild(Suite.java:128)
at org.junit.runners.Suite.runChild(Suite.java:27)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
at
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
at
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
at
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
at
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
2016-05-11 23:32:34,388 [main ] - INFO TransportConnector
- Connector
stomp+nio+ssl://jenkins-test-39e:50013?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536
stopped
2016-05-11 23:32:34,389 [main ] - INFO BrokerService
- Apache ActiveMQ 5.14.0-SNAPSHOT (localhost,
ID:jenkins-test-39e-56729-1463009553425-0:4) uptime 0.036 seconds
2016-05-11 23:32:34,389 [main ] - INFO BrokerService
- Apache ActiveMQ 5.14.0-SNAPSHOT (localhost,
ID:jenkins-test-39e-56729-1463009553425-0:4) is shutdown
Standard Error
Exception in thread "ActiveMQ Transport Server:
stomp+nio://0.0.0.0:0?wireFormat.maxDataLength=102400&wireFormat.maxFrameSize=65536"
java.nio.channels.ClosedSelectorException
at sun.nio.ch.EPollSelectorImpl.putEventOps(EPollSelectorImpl.java:185)
at
sun.nio.ch.ServerSocketChannelImpl.translateAndSetInterestOps(ServerSocketChannelImpl.java:361)
at sun.nio.ch.SelectionKeyImpl.nioInterestOps(SelectionKeyImpl.java:105)
at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:83)
at sun.nio.ch.SelectorImpl.register(SelectorImpl.java:135)
at
java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:209)
at
java.nio.channels.SelectableChannel.register(SelectableChannel.java:277)
at
org.apache.activemq.transport.tcp.TcpTransportServer.run(TcpTransportServer.java:310)
at java.lang.Thread.run(Thread.java:745)
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
