Atmosphere 2.3.1: NPE on JSR356Endpoint close event

[timofeevda]

Environment: Atmosphere 2.3.1 + Tomcat 8.0.22 + JSR356AsyncSupport

I get following exception when websocket connection is being closed on browser page refresh:

22.05.2015 15:58:17 [http-nio-8080-exec-10] org.atmosphere.container.JSR356Endpoint ERROR -- 
java.lang.NullPointerException
    at org.atmosphere.websocket.DefaultWebSocketProcessor.executeClose(DefaultWebSocketProcessor.java:677)
    at org.atmosphere.websocket.DefaultWebSocketProcessor.close(DefaultWebSocketProcessor.java:625)
    at org.atmosphere.container.JSR356Endpoint.onClose(JSR356Endpoint.java:268)
    at org.apache.tomcat.websocket.WsSession.fireEndpointOnClose(WsSession.java:527)
    at org.apache.tomcat.websocket.WsSession.onClose(WsSession.java:511)
    at org.apache.tomcat.websocket.WsFrameBase.processDataControl(WsFrameBase.java:342)
    at org.apache.tomcat.websocket.WsFrameBase.processData(WsFrameBase.java:284)
    at org.apache.tomcat.websocket.WsFrameBase.processInputBuffer(WsFrameBase.java:130)
    at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:60)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onDataAvailable(WsHttpUpgradeHandler.java:203)
    at org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvailable(AbstractServletInputStream.java:198)
    at org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(AbstractProcessor.java:96)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:663)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1521)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1478)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)

Based on my investigation "asynchronousProcessor" variable in DefaultWebSocketProcessor is null in this case. This happens because "started" method is never invoked by atmosphere framework because the creation of JSR356Endpoint in JSR356AsyncSupport occurs later and this startup hook simply goes to the list of hooks and is never invoked.

config.startupHook(new AtmosphereConfig.StartupHook() {
            @Override
            public void started(final AtmosphereFramework framework) {
                if (AsynchronousProcessor.class.isAssignableFrom(framework.getAsyncSupport().getClass())) {
                    asynchronousProcessor = AsynchronousProcessor.class.cast(framework.getAsyncSupport());
                } else {
                    asynchronousProcessor = new AsynchronousProcessor(framework.getAtmosphereConfig()) {
                        @Override
                        public Action service(AtmosphereRequest req, AtmosphereResponse res) throws IOException, ServletException {
                            return framework.getAsyncSupport().service(req, res);
                        }
                    };
                }
            }
        });

Application deployment: there is an unpacked folder in Tomcat webapps directory. On start Tomcats loads apps located in this directory, so the process is pretty straightforward.

Part of the web.xml file:

 <servlet>
        <description>AtmosphereServlet</description>
        <servlet-name>AtmosphereServlet</servlet-name>
        <servlet-class>org.atmosphere.cpr.AtmosphereServlet</servlet-class>
        <init-param>            
            <param-name>org.atmosphere.disableOnStateEvent</param-name>
            <param-value>true</param-value>
        </init-param>       
        <init-param>
            <param-name>org.atmosphere.cpr.broadcaster.shareableThreadPool</param-name>
            <param-value>true</param-value>
        </init-param>
        <init-param>
            <param-name>org.atmosphere.cpr.broadcaster.maxAsyncWriteThreads</param-name>
            <param-value>32</param-value>
        </init-param>
        <load-on-startup>1</load-on-startup>
        <async-supported>true</async-supported>
    </servlet>

In any case JSR356Endpoint creation leading to creation of new DefaultWebSocketProcessor happens on first websocket connection when Atmosphere framework have been already started.

I guess this is very similar to this case discussed in mailing list https://groups.google.com/d/msg/atmosphere-framework/365yvg-UflQ/k73IFY3laB8J

[jfarcand]

started is invoked by the following path when an application gets deployed:

I need to understand why in your case that code isn't executed.

[jfarcand]

OK 1984 will probably fix this issue, but I still need to undestand how your application gets deployed and initialized. Can you put a breakpoint in DefaultWebSocketProcessor and paste the Thread Dump here.

        config.startupHook(new AtmosphereConfig.StartupHook() {

[timofeevda]

Unfortunately, <load-on-startup>0</load-on-startup> didn't help.

Here is the stack trace for the breakpoint you requested:

http-nio-8080-exec-3@12963 daemon, prio=5, in group 'main', status: 'RUNNING'
      at org.atmosphere.websocket.DefaultWebSocketProcessor.configure(DefaultWebSocketProcessor.java:145)
      at org.atmosphere.cpr.WebSocketProcessorFactory.createProcessor(WebSocketProcessorFactory.java:91)
      at org.atmosphere.cpr.WebSocketProcessorFactory.getWebSocketProcessor(WebSocketProcessorFactory.java:60)
      at org.atmosphere.container.JSR356AsyncSupport$AtmosphereConfigurator.getEndpointInstance(JSR356AsyncSupport.java:114)
      at org.apache.tomcat.websocket.server.UpgradeUtil.doUpgrade(UpgradeUtil.java:222)
      at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:77)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
      at com.test.dxwebcore.filters.LoggingFilter.doFilter(LoggingFilter.java:32)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
      at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:617)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518)
      at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)
      at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668)
      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1521)
      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1478)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
      at java.lang.Thread.run(Thread.java:745)

I think 1984 will fix the issue, cause in this case DefaultWebSocketProcessor creation will not depend on the time when JSR356Endpoint is created (in eager or lazy mode).

[jfarcand]

Thanks! I'm puzzled about why the AtmosphereServlet is not intilalized the same ways as the test I'm doing...anyway, 1984 will fix your issue. Closing the bug as fixed, please let me know if not. Thanks for the help.

[timofeevda]

I've just made brief tests with 2.3.2-SNAPSHOT and applied 1984. Looks like now everything is OK. Thanks.