With this tomcat version. Working under stress with http POST calls being fired for uploading and downloading of files. After about 10 to 15 into the test we started seeing broken responses. On investigating the logs we noticed below errors: 01-Jun-2016 18:52:16.153 INFO [http-nio-8080-exec-2] org.apache.coyote.http11.Http11Processor.service Error parsing HTTP request header Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level. java.lang.IllegalStateException: Unexpected state: headers already parsed. Buffer not recycled? at org.apache.coyote.http11.Http11InputBuffer.parseHeaders(Http11InputBuffer.java:589) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1002) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:788) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1485) at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Unknown Source) 01-Jun-2016 18:52:16.154 SEVERE [http-nio-8080-exec-4] org.apache.coyote.http11.Http11Processor.service Error processing request java.lang.NullPointerException at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:389) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1102) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:788) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1485) at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Unknown Source) 01-Jun-2016 18:52:16.160 SEVERE [http-nio-8080-exec-4] org.apache.coyote.http11.Http11Processor.endRequest Error finishing response java.lang.NullPointerException at org.apache.coyote.http11.Http11OutputBuffer.commit(Http11OutputBuffer.java:351) at org.apache.coyote.http11.Http11Processor.action(Http11Processor.java:646) at org.apache.coyote.http11.Http11Processor.endRequest(Http11Processor.java:1785) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1143) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:788) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1485) at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Unknown Source)
Steps to reproduce please. We need the minimal possible test case that demonstrates the issue.
Dropping severity to default.
I have just experienced this error with 8.5.4 Exactly identical logs. The solution was to restart the server. I set the log level on DEBUG, so now I'll have more info when it happens again.
Here is my stacktrace with Tomcat 8.5.4. Seems to be almost identical: 2016-08-24 07:48:38,236 INFO [http-nio-8080-exec-10] o.a.coyote.http11.Http11Processor DirectJDKLog.java:181 Error parsing HTTP request header Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level. java.lang.IllegalStateException: Unexpected state: headers already parsed. Buffer not recycled? at org.apache.coyote.http11.Http11InputBuffer.parseHeaders(Http11InputBuffer.java:587) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1010) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1425) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 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) 2016-08-24 07:48:38,255 ERROR [http-nio-8080-exec-6] o.a.c.c.C.[.[.[.[.w.w.a.b.p.ApiProjectList] DirectJDKLog.java:181 Servlet.service() for servlet [dk.wordmaps.wordmaps4.api.boundary.project.ApiProjectList] in context with path [/api] threw exception java.lang.NullPointerException: null at org.apache.catalina.connector.Request.getServletContext(Request.java:1618) at org.apache.catalina.connector.Request.getContextPath(Request.java:1975) at org.apache.catalina.connector.RequestFacade.getContextPath(RequestFacade.java:784) at dk.wordmaps.wordmaps4.api.boundary.util.security.StatelessSecurityFilter.doFilter(StatelessSecurityFilter.java:58) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) at dk.wordmaps.wordmaps4.api.boundary.util.UTF8ServletFilter.doFilter(UTF8ServletFilter.java:25) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:108) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:522) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) at ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:256) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:349) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1110) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1425) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 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) 2016-08-24 07:48:38,256 ERROR [http-nio-8080-exec-6] o.a.c.c.C.[Catalina].[localhost] DirectJDKLog.java:181 Exception Processing null java.lang.NullPointerException: null at org.apache.catalina.connector.Request.notifyAttributeAssigned(Request.java:1519) at org.apache.catalina.connector.Request.setAttribute(Request.java:1505) at org.apache.catalina.core.StandardWrapperValve.exception(StandardWrapperValve.java:313) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:249) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:108) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:522) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) at ch.qos.logback.access.tomcat.LogbackValve.invoke(LogbackValve.java:256) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:349) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1110) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1425) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 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) 2016-08-24 07:48:38,257 ERROR [http-nio-8080-exec-6] o.a.coyote.http11.Http11Processor DirectJDKLog.java:181 Error processing request java.lang.NullPointerException: null at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:389) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1110) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1425) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 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) 2016-08-24 07:48:38,257 ERROR [http-nio-8080-exec-6] o.a.coyote.http11.Http11Processor DirectJDKLog.java:181 Error finishing response java.lang.NullPointerException: null at org.apache.coyote.http11.Http11OutputBuffer.commit(Http11OutputBuffer.java:351) at org.apache.coyote.http11.Http11Processor.action(Http11Processor.java:658) at org.apache.coyote.http11.Http11Processor.endRequest(Http11Processor.java:1786) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:1149) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1425) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 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)
As a continuation to my previous 2 comments... The Tomcat 8.5.4 server was started yesterday at noon. Everything was fine. By midnight, this error appeared, then most of the POST request triggered this error, even though the requests were totally identical to those sent between noon and midnight. The solution was to restart Tomcat.
Restoring state to NEDDINFO. Absent a way to reproduce this, there is little we can do to investigate.
No test case has been provided so this is being resolved as works for me. Should a test case be provided that demonstrates this issue, it can be re-opened.