ActiveMQ
  1. ActiveMQ
  2. AMQ-1930

NPE during shutdown of embedded activemq

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 5.2.0
    • Fix Version/s: NEEDS_REVIEW
    • Component/s: Transport
    • Labels:
      None
    • Environment:

      revision 675393 of trunk, ActiveMQ 5.2.0

      Description

      I received the following exception from the VMTransport thread when shutting down the broker:

      Async error occurred: java.lang.NullPointerException
      java.lang.NullPointerException
      	at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542)
      	at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64)
      	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
      	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
      	at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
      	at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
      	at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205)
      	at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
      	at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
      	at java.lang.Thread.run(Thread.java:619)
      

      The failure occurred at the following lines of code:

              TransportConnectionState cs = lookupConnectionState(connectionId);
              SessionState ss = cs.getSessionState(sessionId);
      

      It appears that there is a race during shutdown where the connection state is discarded before the last consumer is removed.

        Activity

        Hide
        Timothy Bish added a comment -

        Not test case presented and so far no tests seems to produce this error.

        Show
        Timothy Bish added a comment - Not test case presented and so far no tests seems to produce this error.
        Hide
        A G added a comment -

        I get the same error. This happens while shutting down the application context (using spring with JMS). The logs are attached below.

        20:48:45,685 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException
        java.lang.NullPointerException
        at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542)
        at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205)
        at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
        at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
        20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException
        java.lang.NullPointerException
        at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542)
        at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205)
        at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
        at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
        20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException
        java.lang.NullPointerException
        at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542)
        at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205)
        at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
        at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
        20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException
        java.lang.NullPointerException
        at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542)
        at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205)
        at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
        at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
        20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException
        java.lang.NullPointerException
        at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542)
        at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205)
        at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
        at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
        20:48:45,716 [INFO ] [ache.EhCacheManagerFactoryBean] [main] - Shutting down EHCache CacheManager
        20:48:45,794 [INFO ] [.activemq.broker.BrokerService] [main] - ActiveMQ Message Broker (JmsBroker, ID:u207036-4706-1306176397325-0:0) is shutting down
        20:48:46,372 [INFO ] [vemq.broker.TransportConnector] [main] - Connector tcp://0.0.0.0:4006?wireFormat.maxInactivityDuration=50000 Stopped
        20:48:46,372 [INFO ] [vemq.broker.TransportConnector] [main] - Connector vm://JmsBroker Stopped
        20:48:46,575 [INFO ] [.activemq.broker.BrokerService] [main] - ActiveMQ JMS Message Broker (FinaceJmsBroker, ID:u207036-4706-1306176397325-0:0) stopped

        Show
        A G added a comment - I get the same error. This happens while shutting down the application context (using spring with JMS). The logs are attached below. 20:48:45,685 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException java.lang.NullPointerException at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542) at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205) at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122) at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source) 20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException java.lang.NullPointerException at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542) at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205) at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122) at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source) 20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException java.lang.NullPointerException at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542) at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205) at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122) at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source) 20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException java.lang.NullPointerException at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542) at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205) at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122) at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source) 20:48:45,700 [ERROR] [er.TransportConnection.Service] [VMTransport] - Async error occurred: java.lang.NullPointerException java.lang.NullPointerException at org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:542) at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:64) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:205) at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122) at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source) 20:48:45,716 [INFO ] [ache.EhCacheManagerFactoryBean] [main] - Shutting down EHCache CacheManager 20:48:45,794 [INFO ] [.activemq.broker.BrokerService] [main] - ActiveMQ Message Broker (JmsBroker, ID:u207036-4706-1306176397325-0:0) is shutting down 20:48:46,372 [INFO ] [vemq.broker.TransportConnector] [main] - Connector tcp://0.0.0.0:4006?wireFormat.maxInactivityDuration=50000 Stopped 20:48:46,372 [INFO ] [vemq.broker.TransportConnector] [main] - Connector vm://JmsBroker Stopped 20:48:46,575 [INFO ] [.activemq.broker.BrokerService] [main] - ActiveMQ JMS Message Broker (FinaceJmsBroker, ID:u207036-4706-1306176397325-0:0) stopped
        Hide
        Eduardo Corral added a comment -

        Hi there

        Happens to me with TcpTransport, also occasionally during embedded broker shutdown:

        [ERROR][2008-12-04 13:11:48,770][ActiveMQ Transport: tcp:///127.0.0.1:37584][org.apache.activemq.broker.TransportConnection.Service] Async error occur
        red: java.lang.NullPointerException
        java.lang.NullPointerException
                at org.apache.activemq.broker.TransportConnection.processRemoveSession(TransportConnection.java:589)
                at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:62)
                at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:305)
                at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
                at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
                at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143)
                at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:206)
                at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
                at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
                at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
                at java.lang.Thread.run(Unknown Source)
        
        Show
        Eduardo Corral added a comment - Hi there Happens to me with TcpTransport, also occasionally during embedded broker shutdown: [ERROR][2008-12-04 13:11:48,770][ActiveMQ Transport: tcp:///127.0.0.1:37584][org.apache.activemq.broker.TransportConnection.Service] Async error occur red: java.lang.NullPointerException java.lang.NullPointerException at org.apache.activemq.broker.TransportConnection.processRemoveSession(TransportConnection.java:589) at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:62) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:305) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68) at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143) at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:206) at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84) at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203) at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185) at java.lang.Thread.run(Unknown Source)
        Hide
        Scott Stanton added a comment -

        Not really. It happens occasionally during our automated testing when
        we shut down our server, but I haven't been able to force it to happen
        on command. I didn't see anything of note in the log prior to the
        failure that would give any clues to the problem. If you have a
        suggestion for logging statements to add, I'd be happy to put them into
        our system and see if we can collect some more details.

        Show
        Scott Stanton added a comment - Not really. It happens occasionally during our automated testing when we shut down our server, but I haven't been able to force it to happen on command. I didn't see anything of note in the log prior to the failure that would give any clues to the problem. If you have a suggestion for logging statements to add, I'd be happy to put them into our system and see if we can collect some more details.
        Hide
        Gary Tully added a comment -

        is this easy to reproduce?

        Show
        Gary Tully added a comment - is this easy to reproduce?

          People

          • Assignee:
            Unassigned
            Reporter:
            Scott Stanton
          • Votes:
            1 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development