Payara
Payara copied to clipboard
Bug Report: Occasionally, a NullPointerException is thrown when the Websocket is closed due to Idle Timeout/FISH-5786.
Description
Occasionally, a NullPointerException is thrown when the Websocket is closed due to Idle Timeout. It appears to be timing dependent. In the case of one application using Atmosphere, an exception was thrown about 30% of the time.
Expected Outcome
No exceptions will be thrown.
Current Outcome
In rare cases, the following Exception will be thrown.
[2021-10-04T22:37:15.615+0900] [Payara 5.2021.7] [重大] [AS-WEB-CORE-00037] [javax.enterprise.web.core] [tid: _ThreadID=100 _ThreadName=http-thread-pool::http-listener-1(1)] [timeMillis: 1633354635615] [levelValue: 1000] [[
An exception or error occurred in the container during the request processing
java.lang.NullPointerException
at org.glassfish.grizzly.http.util.HttpCodecUtils.parseHost(HttpCodecUtils.java:45)
at org.glassfish.grizzly.http.HttpRequestPacket.doParseHostHeader(HttpRequestPacket.java:737)
at org.glassfish.grizzly.http.HttpRequestPacket.parseHostHeader(HttpRequestPacket.java:731)
at org.glassfish.grizzly.http.HttpRequestPacket.serverName(HttpRequestPacket.java:275)
at org.glassfish.grizzly.http.server.Request.getServerName(Request.java:1276)
at org.apache.catalina.connector.Request.getServerName(Request.java:1627)
at org.apache.catalina.connector.RequestFacade.getServerName(RequestFacade.java:501)
at com.sun.enterprise.web.connector.coyote.PECoyoteConnector.requestStartEvent(PECoyoteConnector.java:1198)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:346)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:238)
at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:520)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:217)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:182)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:156)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:218)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.base/java.lang.Thread.run(Thread.java:829)
]]
[2021-10-04T22:37:15.620+0900] [Payara 5.2021.7] [警告] [] [org.glassfish.grizzly.filterchain.DefaultFilterChain] [tid: _ThreadID=100 _ThreadName=http-thread-pool::http-listener-1(1)] [timeMillis: 1633354635620] [levelValue: 900] [[
GRIZZLY0013: Exception during FilterChain execution
java.lang.NullPointerException
at org.glassfish.grizzly.attributes.Attribute.remove(Attribute.java:172)
at org.glassfish.grizzly.http.server.HttpServerFilter.afterService(HttpServerFilter.java:372)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:243)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.base/java.lang.Thread.run(Thread.java:829)
]]
Also, in the case of one application that uses Atmosphere, after the warning "Unable to set request character encoding to UTF-8 from context /xxx, because request parameters have already been read, or ServletRequest. getReader() has already been called", and then the following Exception was thrown.
[#|2021-10-02T00:23:13.562+0900|重大|Payara 5.2021.7|javax.enterprise.web.core|_ThreadID=102;_ThreadName=http-thread-pool::http-listener-1(4);_TimeMillis=1633101793562;_LevelValue=1000;_MessageID=AS-WEB-CORE-00037;|
An exception or error occurred in the container during the request processing
java.lang.NullPointerException
at org.apache.catalina.connector.Request.setContext(Request.java:699)
at com.sun.enterprise.web.pwc.connector.coyote.PwcCoyoteRequest.setContext(PwcCoyoteRequest.java:93)
at org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:538)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:309)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:238)
at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:520)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:217)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:182)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:156)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:218)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.base/java.lang.Thread.run(Thread.java:829)
|#]
[#|2021-10-02T00:23:13.563+0900|警告|Payara 5.2021.7|org.glassfish.grizzly.filterchain.DefaultFilterChain|_ThreadID=102;_ThreadName=http-thread-pool::http-listener-1(4);_TimeMillis=1633101793563;_LevelValue=900;|
GRIZZLY0013: Exception during FilterChain execution
java.lang.NullPointerException
at org.glassfish.grizzly.attributes.Attribute.remove(Attribute.java:172)
at org.glassfish.grizzly.http.server.HttpServerFilter.afterService(HttpServerFilter.java:372)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:243)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.base/java.lang.Thread.run(Thread.java:829)
|#]
Steps to reproduce
- Build the following Appilication. mvn clean package
- https://github.com/otukatigayim/payara-websocket
- bin/asadmin start-domain
- bin/asadmin deploy --contextroot=payara-websocket --name=payara-websocket --virtualservers=server payara-websocket.war
- Access http://localhost:8080/payara-websocket/index.jsp with a browser.
- View the server.log.
Environment
- Distribution: 5.2021.7 Server Full Profile
- JDK Version: OpenJDK 64-Bit Server VM Corretto-11.0.12.7.1 (build 11.0.12+7-LTS, mixed mode)
- Operating System: Windows
After changing the max idle time, I was able to increase the probability of an Exception being thrown.
- https://github.com/otukatigayim/payara-websocket/pull/1
In addition, the following Exception was sometimes thrown.
[2021-10-05T10:46:34.726+0900] [Payara 5.2021.7] [�d��] [AS-WEB-CORE-00037] [javax.enterprise.web.core] [tid: _ThreadID=117 _ThreadName=http-thread-pool::http-listener-1(4)] [timeMillis: 1633398394726] [levelValue: 1000] [[
An exception or error occurred in the container during the request processing
java.lang.NullPointerException
at org.glassfish.grizzly.http.Method.<init>(Method.java:121)
at org.glassfish.grizzly.http.Method.CUSTOM(Method.java:57)
at org.glassfish.grizzly.http.Method.CUSTOM(Method.java:52)
at org.glassfish.grizzly.http.Method.valueOf(Method.java:82)
at org.glassfish.grizzly.http.HttpRequestPacket.getMethod(HttpRequestPacket.java:164)
at org.glassfish.grizzly.http.server.Request.getMethod(Request.java:1773)
at org.apache.catalina.connector.Request.getMethod(Request.java:2448)
at org.apache.catalina.connector.RequestFacade.getMethod(RequestFacade.java:742)
at com.sun.enterprise.web.connector.coyote.PECoyoteConnector.requestEndEvent(PECoyoteConnector.java:1228)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:378)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:238)
at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:520)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:217)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:182)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:156)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:218)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.lang.Thread.run(Thread.java:748)
]]
[2021-10-05T10:46:34.726+0900] [Payara 5.2021.7] [�x��] [] [org.glassfish.grizzly.filterchain.DefaultFilterChain] [tid: _ThreadID=117 _ThreadName=http-thread-pool::http-listener-1(4)] [timeMillis: 1633398394726] [levelValue: 900] [[
GRIZZLY0013: Exception during FilterChain execution
java.lang.NullPointerException
at org.glassfish.grizzly.attributes.Attribute.remove(Attribute.java:172)
at org.glassfish.grizzly.http.server.HttpServerFilter.afterService(HttpServerFilter.java:372)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:243)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.lang.Thread.run(Thread.java:748)
]]
[2021-10-05T10:46:41.764+0900] [Payara 5.2021.7] [�d��] [AS-WEB-CORE-00037] [javax.enterprise.web.core] [tid: _ThreadID=118 _ThreadName=http-thread-pool::http-listener-1(5)] [timeMillis: 1633398401764] [levelValue: 1000] [[
An exception or error occurred in the container during the request processing
java.lang.NullPointerException
at org.apache.catalina.connector.OutputBuffer.reset(OutputBuffer.java:473)
at org.apache.catalina.connector.Response.resetBuffer(Response.java:873)
at org.apache.catalina.connector.Response.resetBuffer(Response.java:852)
at org.apache.catalina.connector.Response.sendError(Response.java:1474)
at org.apache.catalina.connector.Response.sendError(Response.java:1440)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:359)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:238)
at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:520)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:217)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:182)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:156)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:218)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.lang.Thread.run(Thread.java:748)
]]
[2021-10-05T10:46:41.765+0900] [Payara 5.2021.7] [�x��] [] [javax.enterprise.web] [tid: _ThreadID=118 _ThreadName=http-thread-pool::http-listener-1(5)] [timeMillis: 1633398401765] [levelValue: 900] [[
Response Error during finishResponse
java.lang.NullPointerException
at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:245)
at org.apache.catalina.connector.Response.finishResponse(Response.java:621)
at org.apache.catalina.connector.CoyoteAdapter$CatalinaAfterServiceListener.onAfterService(CoyoteAdapter.java:1013)
at org.glassfish.grizzly.http.server.Request.onAfterService(Request.java:595)
at org.glassfish.grizzly.http.server.HttpServerFilter.afterService(HttpServerFilter.java:374)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:243)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:33)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
at java.lang.Thread.run(Thread.java:748)
]]
Hi @otukatigayim, I am able to reproduce this issue. I have raised an internal issue with JIRA FISH-5786. Thanks. It may take a while to fix the issue. You are free to submit a PR to fix this issue if you feel confident to do so.