Tomcat 7.0.50 (proposed for voting at the time of submitting this issue) with Oracle Java 1.7.0_40 on Win7 64-bit, sometimes returns incorrect response when NIO connector is used. Start of the report, and steps to reproduce the problem are in this thread: http://www.mail-archive.com/dev@tomcat.apache.org/msg80175.html -Ognjen
Java client is used for smoke testing Tomcat 7.0.50. Java client fails with following exception: ==== Exception in thread "main" java.lang.RuntimeException: java.io.IOException: Invalid Http response at webcrawler.WebCrawler.getpage(WebCrawler.java:117) at webcrawler.WebCrawler.repeat(WebCrawler.java:191) at webcrawler.WebCrawler.main(WebCrawler.java:30) Caused by: java.io.IOException: Invalid Http response at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1342) at java.net.URL.openStream(URL.java:1037) at webcrawler.WebCrawler.getpage(WebCrawler.java:94) ... 2 more ---- Relevant lines from sun.net.www.protocol.http.HttURLConnection.getInputStream: ==== respCode = getResponseCode(); if (respCode == -1) { disconnectInternal(); throw new IOException ("Invalid Http response"); } ---- So, getResponseCode returns -1. Relevant part from sun.net.www.protocol.http.HttURLConnection.getResponseCode(): ==== /* * Examine the status-line - should be formatted as per * section 6.1 of RFC 2616 :- * * Status-Line = HTTP-Version SP Status-Code SP Reason-Phrase * * If status line can't be parsed return -1. */ if (statusLine.startsWith("HTTP/1.")) { int codePos = statusLine.indexOf(' '); if (codePos > 0) { int phrasePos = statusLine.indexOf(' ', codePos+1); if (phrasePos > 0 && phrasePos < statusLine.length()) { responseMessage = statusLine.substring(phrasePos+1); } // deviation from RFC 2616 - don't reject status line // if SP Reason-Phrase is not included. if (phrasePos < 0) phrasePos = statusLine.length(); try { responseCode = Integer.parseInt (statusLine.substring(codePos+1, phrasePos)); return responseCode; } catch (NumberFormatException e) { } } } return -1; ---- So it seems that response from Tomcat doesn't contain string "HTTP/1." in the first line.
Created attachment 31182 [details] Correct request and correct response
Created attachment 31183 [details] Correct request and broken response
I took localhost dump using RawCap. The dump contains traffic from the smoke testing. I then opened it with wireshark. In the dump, there is a number of requests for file prelude.jspf.html: "GET /examples/jsp/jsp2/misc/prelude.jspf.html HTTP/1.1" Tomcat generally responds correctly, as seen in attachment 31182 [details]. But, in one request, instead of responding with content from "prelude.jspf.html" Tomcat responds with partial content from a different file -- "/docs/architecture/startup/serverStartup.txt". As one can see in attachment 31183 [details], the response also doesn't contain any header. That is the reason why Java client fails.
Can you provide the source code of the test client you are using so the committers can try and reproduce this?
Created attachment 31184 [details] Java test class Here is Java class used for testing. You should call it with one argument - starting URL (e.g. "http://localhost:8080/") At the first phase, it crawls all pages starting from the root. During the crawl, Java stack traces for 401s and 404s will be printed on the console, and may be ignored. At the second phase, it will repeatedly read all collected URLs, 500 times in a row. In total, it reads around 140k pages. If there is an error during the test, exception will be thrown, e.g: ==== Round: 154 / 500 Round: 155 / 500 Round: 156 / 500 Exception in thread "main" java.lang.RuntimeException: java.io.IOException: Invalid Http response at webcrawler.WebCrawler.getpage(WebCrawler.java:117) at webcrawler.WebCrawler.repeat(WebCrawler.java:191) at webcrawler.WebCrawler.main(WebCrawler.java:30) Caused by: java.io.IOException: Invalid Http response at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1342) at java.net.URL.openStream(URL.java:1037) at webcrawler.WebCrawler.getpage(WebCrawler.java:94) ... 2 more ---- Sometimes exception is thrown after 5k requests, sometimes only after running this test several times. -Ognjen
Created attachment 31185 [details] TCP data log (In reply to Ognjen Blagojevic from comment #6) > Created attachment 31184 [details] > Java test class Hi, I can reproduce the problem with your test class with Tomcat 7.0.50, Tomcat 7.0.47 and Tomcat 8.0.0-RC10 on Windows 8.1 x64 with Java 1.7.0_45. To provide an additional example of a broken HTTP response, I used a self-written tool to intercept the TCP connections from the Java client to Tomcat and log all data of each TCP connection channel to a file and I attached a Zip file containing the logs of the last few TCP connections. The logs of connections 262-267 look normal (each HTTP request is replied to with an HTTP response), but if you look at 268 (where a single HTTP request was sent), Tomcat did not start the reply with an HTTP response, but with some random data chunks that seem to belong to different responses, and later sent the actual HTTP response for the request.
(In reply to Konstantin Preißer from comment #7) > I can reproduce the problem with your test class with Tomcat 7.0.50, Tomcat > 7.0.47 and Tomcat 8.0.0-RC10 on Windows 8.1 x64 with Java 1.7.0_45. So that's critical information -- this isn't a regression since 7.0.47, i.e. in the 7.0.50 release. It might be a regression in 7.0.47, but that was already released as stable.
Can someone who has been able to repeat this please test with tomcat/trunk from svn and see if they can still repeat it. I have been trying to repeat this for several hours with no success. I am wondering if the root cause is a bug that has been fixed since the last release.
Created attachment 31190 [details] multi-threaded WebCrawler Slightly enhanced version of the provided WebCrawler class: - Params URL ITERATIONS THREADS (crawl recursively starting at URL, retrieve found list of pages ITERATIONS times distributed on THREADS threads) - Log timestamp if an error occurs - don't convert bytes to strings when in replay mode Example: /path/to/bin/java webcrawler.WebCrawler http://myserver:8080/docs/ 1000 10 Code tunables: public static final int BUFSZ = 1000; // Buffer size for reading responses public static final int CONNECT_TIMEOUT = 5000; // Connect timeout public static final int READ_TIMEOUT = 30000; // Connect timeout
Created attachment 31191 [details] Alternative Testcase - WAR
Created attachment 31192 [details] Alternative Test Case - Java class Hi Mark, (In reply to Mark Thomas from comment #9) > Can someone who has been able to repeat this please test with tomcat/trunk > from svn and see if they can still repeat it. I have been trying to repeat > this for several hours with no success. I am wondering if the root cause is > a bug that has been fixed since the last release. I could reproduce the issues with Tomcat 8 trunk, SVN r1556836 on Windows 8.1 x64, Java 1.7.0_45 x64. I uploaded an alternative Testcase which maybe makes reproducing easier - a WAR that contains 100 text files, and a Java class that starts 100 Threads that concurrently download 100 URLs. Normally, the only things that should be displayed in the console are "Starting..." and "Finished.". This happens when running with the BIO connector. However, with Tomcat NIO connector, I mostly get exceptions like this: java.io.IOException: Invalid Http response at sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source) at test.TomcatNioTest.readUrl(TomcatNioTest.java:23) at test.TomcatNioTest.access$0(TomcatNioTest.java:19) at test.TomcatNioTest$1.run(TomcatNioTest.java:48) at java.lang.Thread.run(Unknown Source) Exception in thread "Thread-93" java.lang.RuntimeException: Size mismatch for URL http://localhost:8080/testnio/files/TextFile81.txt - Expected: 58003, Got: 65536 at test.TomcatNioTest.readUrl(TomcatNioTest.java:31) at test.TomcatNioTest.access$0(TomcatNioTest.java:19) at test.TomcatNioTest$1.run(TomcatNioTest.java:48) at java.lang.Thread.run(Unknown Source) Also, most of the time the program never finishes - it seems Tomcat does not serve some requests. Sometimes I also get these Exceptions in Tomcat: 09-Jan-2014 17:40:48.143 SEVERE [http-nio-8080-exec-76] org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request java.lang.NullPointerException at org.apache.coyote.http11.Http11NioProcessor.actionInternal(Http11NioProcessor.java:321) at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:843) at org.apache.coyote.Request.action(Request.java:381) at org.apache.catalina.connector.Request.getRemoteAddr(Request.java:1240) at org.apache.catalina.connector.Request.getRemoteHost(Request.java:1255) at org.apache.catalina.valves.AccessLogValve$HostElement.addElement(AccessLogValve.java:1366) at org.apache.catalina.valves.AccessLogValve.log(AccessLogValve.java:963) at org.apache.catalina.core.AccessLogAdapter.log(AccessLogAdapter.java:51) at org.apache.catalina.core.ContainerBase.logAccess(ContainerBase.java:1044) at org.apache.catalina.core.ContainerBase.logAccess(ContainerBase.java:1051) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:573) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1015) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:646) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) 09-Jan-2014 17:40:48.518 WARNING [http-nio-8080-exec-76] org.apache.catalina.connector.CoyoteAdapter.log Exception while attempting to add an entry to the access log java.lang.NullPointerException at org.apache.coyote.http11.Http11NioProcessor.actionInternal(Http11NioProcessor.java:321) at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:843) at org.apache.coyote.Request.action(Request.java:381) at org.apache.catalina.connector.Request.getRemoteAddr(Request.java:1240) at org.apache.catalina.connector.Request.getRemoteHost(Request.java:1255) at org.apache.catalina.valves.AccessLogValve$HostElement.addElement(AccessLogValve.java:1366) at org.apache.catalina.valves.AccessLogValve.log(AccessLogValve.java:963) at org.apache.catalina.core.AccessLogAdapter.log(AccessLogAdapter.java:51) at org.apache.catalina.core.StandardEngine.logAccess(StandardEngine.java:344) at org.apache.catalina.connector.CoyoteAdapter.log(CoyoteAdapter.java:644) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1044) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:646) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) 09-Jan-2014 17:47:37.091 SEVERE [http-nio-8080-ClientPoller-1] org.apache.tomcat.util.net.NioEndpoint.processSocket Error allocating socket processor java.lang.NullPointerException at org.apache.tomcat.util.net.NioEndpoint.processSocket(NioEndpoint.java:622) at org.apache.tomcat.util.net.NioEndpoint$Poller.processKey(NioEndpoint.java:1144) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1101) at java.lang.Thread.run(Thread.java:744)
I can reproduce errors even for trunk but there currently only read timeouts. I'm using a relatively slow server and remote access from a more powerful machine using 10 threads in the improved version of the WebCrawler. Crawling the docs/ webapp suffices to produce those read timeouts (30 seconds). The CPU on the server is not fully saturated and other parametrization shows that those requests would hang indefinitely if no timeout were applied. For TC 7.0.50 I could also produce other types of errors, but didn't play long enough with trunk. Not directly related to the read timeout occurences I see on the server side sometimes messages: 09-Jan-2014 17:56:33.691 SEVERE [http-nio-8080-ClientPoller-1] org.apache.tomcat.util.net.NioEndpoint$PollerEvent.run java.nio.channels.ClosedChannelException at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:194) at org.apache.tomcat.util.net.NioEndpoint$PollerEvent.run(NioEndpoint.java:797) at org.apache.tomcat.util.net.NioEndpoint$Poller.events(NioEndpoint.java:925) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1085) at java.lang.Thread.run(Thread.java:744) Regards, Rainer
When crawling not only /docs but also /examples, I get more types of errors. In the access log (non-200, non-302) 195.227.30.185 - - 18:11:12.441 "GET /docs/cgi-howto.html HTTP/1.1" 400 - - - - 00:59:59.00-1 "-" 500 - 195.227.30.185 - - 18:11:12.895 "GET /examples/jsp/jsp2/simpletag/book.jsp HTTP/1.1" 400 951 195.227.30.185 - - 18:11:13.050 "GET /examples/jsp/jsp2/simpletag/book.jsp HTTP/1.1" 400 951 195.227.30.185 - - 18:11:33.967 "GET /examples/servlets/nonblocking/numberwriter HTTP/1.1" 500 49200 195.227.30.185 - - 18:11:35.036 "GET /examples/servlets/nonblocking/numberwriter HTTP/1.1" 500 155800 - - - 00:59:59.00-1 "-" 500 - - - - 00:59:59.00-1 "-" 400 - 195.227.30.185 - - 18:11:35.486 "GET /docs/jspapi/index.html HTTP/1.1" 400 - 195.227.30.185 - - 18:11:35.674 "GET /examples/jsp/jsp2/jspattribute/jspattribute.html HTTP/1.1" 500 2221 - - - 00:59:59.00-1 "-" 500 - 195.227.30.185 - - 18:11:35.888 "GET /docs/config/cluster-valve.html HTTP/1.1" 400 10669 195.227.30.185 - - 18:11:35.887 "GET /docs/config/cluster-valve.html HTTP/1.1" 400 - etc. In the tomcat logs 09-Jan-2014 18:10:40.405 SEVERE [http-nio-8080-ClientPoller-1] org.apache.tomcat.util.net.NioEndpoint$PollerEvent.run java.nio.channels.ClosedChannelException at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:194) at org.apache.tomcat.util.net.NioEndpoint$PollerEvent.run(NioEndpoint.java:797) at org.apache.tomcat.util.net.NioEndpoint$Poller.events(NioEndpoint.java:925) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1085) at java.lang.Thread.run(Thread.java:744) 09-Jan-2014 18:11:11.341 SEVERE [http-nio-8080-exec-9] org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process Error reading request, ignored java.lang.NullPointerException at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.release(Http11NioProtocol.java:243) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:698) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) 09-Jan-2014 18:11:12.450 INFO [http-nio-8080-exec-26] org.apache.coyote.http11.AbstractHttp11Processor.process Error parsing HTTP request header Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level. 09-Jan-2014 18:11:12.745 SEVERE [http-nio-8080-exec-29] org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request java.lang.NullPointerException at org.apache.catalina.connector.Request.notifyAttributeAssigned(Request.java:1512) at org.apache.catalina.connector.Request.setAttribute(Request.java:1503) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:162) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:76) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:934) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:90) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:522) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1015) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:646) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) 09-Jan-2014 18:11:12.752 SEVERE [http-nio-8080-exec-29] org.apache.coyote.http11.AbstractHttp11Processor.endRequest Error finishing response java.lang.NullPointerException at org.apache.coyote.http11.InternalNioOutputBuffer.flushBuffer(InternalNioOutputBuffer.java:235) at org.apache.coyote.http11.InternalNioOutputBuffer.addToBB(InternalNioOutputBuffer.java:190) at org.apache.coyote.http11.InternalNioOutputBuffer.access$000(InternalNioOutputBuffer.java:42) at org.apache.coyote.http11.InternalNioOutputBuffer$SocketOutputBuffer.doWrite(InternalNioOutputBuffer.java:321) at org.apache.coyote.http11.filters.ChunkedOutputFilter.end(ChunkedOutputFilter.java:166) at org.apache.coyote.http11.AbstractOutputBuffer.endRequest(AbstractOutputBuffer.java:379) at org.apache.coyote.http11.AbstractHttp11Processor.endRequest(AbstractHttp11Processor.java:1704) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1071) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:646) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) ... 09-Jan-2014 18:11:33.966 SEVERE [http-nio-8080-exec-9] org.apache.catalina.connector.CoyoteAdapter.asyncDispatch Exception while processing an asynchronous request java.lang.IllegalStateException: Calling [asyncTimeout()] is not valid for a request with Async state [READ_WRITE_OP] at org.apache.coyote.AsyncStateMachine.asyncTimeout(AsyncStateMachine.java:265) at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:802) at org.apache.coyote.Request.action(Request.java:381) at org.apache.catalina.core.AsyncContextImpl.timeout(AsyncContextImpl.java:139) at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:306) at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1618) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:640) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) 09-Jan-2014 18:11:34.685 SEVERE [http-nio-8080-exec-21] org.apache.catalina.connector.CoyoteAdapter.asyncDispatch Exception while processing an asynchronous request java.lang.IllegalStateException: In non-blocking mode you may not write to the ServletOutputStream until the previous write has completed and isReady() returns true at org.apache.catalina.connector.CoyoteOutputStream.checkNonBlockingWrite(CoyoteOutputStream.java:128) at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:96) at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:90) at nonblocking.NumberWriter$NumberWriterListener.onWritePossible(NumberWriter.java:132) at nonblocking.NumberWriter$NumberWriterListener.onAllDataRead(NumberWriter.java:120) at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:391) at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1618) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:631) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) 09-Jan-2014 18:11:34.967 SEVERE [http-nio-8080-exec-20] org.apache.catalina.connector.CoyoteAdapter.asyncDispatch Exception while processing an asynchronous request java.lang.IllegalStateException: The request associated with the AsyncContext has already completed processing. at org.apache.catalina.core.AsyncContextImpl.check(AsyncContextImpl.java:532) at org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:91) at nonblocking.NumberWriter$NumberWriterListener.onError(NumberWriter.java:145) at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:395) at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1618) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:631) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) ... 09-Jan-2014 18:11:36.787 SEVERE [http-nio-8080-exec-4] org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request java.lang.NullPointerException at org.apache.tomcat.util.buf.MessageBytes.toChars(MessageBytes.java:228) at org.apache.catalina.mapper.Mapper.map(Mapper.java:665) at org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:794) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:517) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1015) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:646) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) Some of which are possibly because the client calls URLs that it shouldn't.
(In reply to Konstantin Preißer from comment #11) > Created attachment 31191 [details] > Alternative Testcase - WAR Thanks. I can repeat the problem with that variation of the test case. My testing shows the issue is related to sendFile. If I set useSendFile="false" on the NIO connector everything works as expected. I'm looking at the sendFile code now to see if I can figure out where I (assuming it was me but it is a pretty good bet that it was) broke it.
Just in case others want to check as well, it is useSendfile="false" (lower case "file"). Running test with my multi-threaded version of the crawler against alls tc webaps right now. Looks better than before, no errors yet, will let it run for another hour or so.
I believe I have fixed this in 8.0.x trunk. I'd be grateful if one or more of you who were able to repeat this issue are able to validate (or not) my fix.
So far so good. Tomcat 8 trunk (r1556957) works for me. No exception on client side, or in server logs, no HTTP 500 errors.
Looks promising. I did not get any errors with sendfile turned off and 50000 iterations distributed on 20 threads. I now run the recent trunk with your fix again with 20 threads and the first 2000 iterations are good. I'll let it run until 50000 and will check tomorrow whether 7.0.50 runs without problems when switching off sendfile.!gre
Fixed applied to 7.0.x for 7.0.51 onwards.
(In reply to Mark Thomas from comment #20) > Fixed applied to 7.0.x for 7.0.51 onwards. Tomcat 7.0.x trunk also works correctly. I'm closing this bug.