You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by bu...@apache.org on 2014/01/08 10:52:04 UTC

[Bug 55976] New: Broken response from NIO connector in Tomcat 7.0.50

https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

            Bug ID: 55976
           Summary: Broken response from NIO connector in Tomcat 7.0.50
           Product: Tomcat 7
           Version: trunk
          Hardware: PC
            Status: NEW
          Severity: normal
          Priority: P2
         Component: Connectors
          Assignee: dev@tomcat.apache.org
          Reporter: ognjen.d.blagojevic@gmail.com

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

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #13 from Rainer Jung <ra...@kippdata.de> ---
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

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

Ognjen Blagojevic <og...@gmail.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 OS|                            |All

--- Comment #1 from Ognjen Blagojevic <og...@gmail.com> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

Peter De Wachter <pd...@gmail.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |pdewacht@gmail.com

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

Ognjen Blagojevic <og...@gmail.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED

--- Comment #21 from Ognjen Blagojevic <og...@gmail.com> ---
(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.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #12 from Konstantin Preißer <kp...@apache.org> ---
Created attachment 31192
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=31192&action=edit
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)

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #11 from Konstantin Preißer <kp...@apache.org> ---
Created attachment 31191
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=31191&action=edit
Alternative Testcase - WAR

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #14 from Rainer Jung <ra...@kippdata.de> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #18 from Ognjen Blagojevic <og...@gmail.com> ---
So far so good. Tomcat 8 trunk (r1556957) works for me. No exception on client
side, or in server logs, no HTTP 500 errors.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #16 from Rainer Jung <ra...@kippdata.de> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #5 from Mark Thomas <ma...@apache.org> ---
Can you provide the source code of the test client you are using so the
committers can try and reproduce this?

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #15 from Mark Thomas <ma...@apache.org> ---
(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.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|---                         |FIXED

--- Comment #20 from Mark Thomas <ma...@apache.org> ---
Fixed applied to 7.0.x for 7.0.51 onwards.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #9 from Mark Thomas <ma...@apache.org> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #6 from Ognjen Blagojevic <og...@gmail.com> ---
Created attachment 31184
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=31184&action=edit
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

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #8 from Jess Holle <je...@ptc.com> ---
(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.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #4 from Ognjen Blagojevic <og...@gmail.com> ---
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.

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, the response also doesn't contain any
header. That is the reason why Java client fails.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #2 from Ognjen Blagojevic <og...@gmail.com> ---
Created attachment 31182
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=31182&action=edit
Correct request and correct response

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #10 from Rainer Jung <ra...@kippdata.de> ---
Created attachment 31190
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=31190&action=edit
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

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #7 from Konstantin Preißer <kp...@apache.org> ---
Created attachment 31185
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=31185&action=edit
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

Konstantin Preißer <kp...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
  Attachment #31192|text/java                   |text/plain
          mime type|                            |

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #3 from Ognjen Blagojevic <og...@gmail.com> ---
Created attachment 31183
  --> https://issues.apache.org/bugzilla/attachment.cgi?id=31183&action=edit
Correct request and broken response

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #17 from Mark Thomas <ma...@apache.org> ---
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.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 55976] Broken response from NIO connector in Tomcat 7.0.50

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=55976

--- Comment #19 from Rainer Jung <ra...@kippdata.de> ---
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

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org