2015-02-17 16:49 GMT+03:00 Mark Thomas <ma...@apache.org>:
> On 16/02/2015 14:09, Konstantin Kolinko wrote:
>> 2015-02-15 21:46 GMT+03:00 Mark Thomas <ma...@apache.org>:
>>> The proposed Apache Tomcat 8.0.20 release is now available for voting.
>>>
>>>
>>> The proposed 8.0.20 release is:
>>> [ ] Broken - do not release
>>> [ ] Stable - go ahead and release as 8.0.20
>>>
>>
>> I am abstaining for now.
>>
>> Using JDK 7u76, win, 32-bit
>> Unit tests pass.
>>
>> Smoke testing: I see an issue with numberwriter example.
>>
>> Test:
>> 1) go to /examples/servlets/nonblocking/numberwriter with a web browser
>> 2) look into access log
>> Expected: status 200
>> Actual: status 500 for APR, NIO, NIO2. (BIO is OK)
>>
>> NIO sometimes show status 200.
>> NIO+HTTPS shows status 200.
>
> How frequently do you see this? I've just tried repeating this with NIO
> on Windows (64-bit OS, 32-bit u76 JDK, 8.0.x) without success.
>
> I've tired a few other OS / JDK combinations that are less like your
> environment and I haven't been able to repeat this there either.
I am observing this consistently. Though as it disappeared with HTTPS
connector it depends on timing. I configured HTTPS Nio2 connector and
I observe this issue there as well.
I enabled FINE logging for Coyote and I am seeing the following
messages for a single request:
[[[
18-Feb-2015 15:51:16.372 FINE [http-nio2-127.0.0.1-8084-exec-2]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.register
Register
Catalina:type=RequestProcessor,worker="http-nio2-127.0.0.1-8084",name=HttpRequest1
18-Feb-2015 15:51:16.378 FINE [http-nio2-127.0.0.1-8084-exec-2]
org.apache.coyote.http11.AbstractNioInputBuffer.parseRequestLine
Received [GET /examples/servlets/nonblocking/numberwriter HTTP/1.1
Host: localhost:8084
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:35.0)
Gecko/20100101 Firefox/35.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: ru-RU,ru;q=0.8,en-US;q=0.5,en;q=0.3
Accept-Encoding: gzip, deflate
Connection: keep-alive
Cache-Control: max-age=0
]
18-Feb-2015 15:51:16.611 FINE [http-nio2-127.0.0.1-8084-exec-2]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_READ], State out: [LONG]
18-Feb-2015 15:51:16.663 FINE [http-nio2-127.0.0.1-8084-exec-2]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_READ], State out: [LONG]
18-Feb-2015 15:51:16.865 FINE [http-nio2-127.0.0.1-8084-exec-4]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:16.894 FINE [http-nio2-127.0.0.1-8084-exec-6]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:16.917 FINE [http-nio2-127.0.0.1-8084-exec-8]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:16.940 FINE [http-nio2-127.0.0.1-8084-exec-10]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:16.957 FINE [http-nio2-127.0.0.1-8084-exec-2]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:16.975 FINE [http-nio2-127.0.0.1-8084-exec-4]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:16.984 FINE [http-nio2-127.0.0.1-8084-exec-6]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:16.991 FINE [http-nio2-127.0.0.1-8084-exec-8]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.006 FINE [http-nio2-127.0.0.1-8084-exec-10]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.014 FINE [http-nio2-127.0.0.1-8084-exec-3]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.023 FINE [http-nio2-127.0.0.1-8084-exec-2]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.032 FINE [http-nio2-127.0.0.1-8084-exec-7]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.053 FINE [http-nio2-127.0.0.1-8084-exec-8]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.060 FINE [http-nio2-127.0.0.1-8084-exec-3]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.068 FINE [http-nio2-127.0.0.1-8084-exec-5]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.078 FINE [http-nio2-127.0.0.1-8084-exec-7]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.085 FINE [http-nio2-127.0.0.1-8084-exec-9]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.093 FINE [http-nio2-127.0.0.1-8084-exec-10]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.107 FINE [http-nio2-127.0.0.1-8084-exec-8]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.116 FINE [http-nio2-127.0.0.1-8084-exec-3]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.131 FINE [http-nio2-127.0.0.1-8084-exec-5]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.143 FINE [http-nio2-127.0.0.1-8084-exec-1]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.155 FINE [http-nio2-127.0.0.1-8084-exec-4]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:51:17.169 FINE [http-nio2-127.0.0.1-8084-exec-10]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [ASYNC_END]
18-Feb-2015 15:51:17.170 FINE [http-nio2-127.0.0.1-8084-exec-10]
org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch Unable
to write async data.
java.lang.IllegalStateException: Calling [asyncOperation()] is not
valid for a request with Async state [DISPATCHED]
at
org.apache.coyote.AsyncStateMachine.asyncOperation(AsyncStateMachine.java:207)
at
org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1658)
at
org.apache.coyote.http11.Http11Nio2Processor.asyncDispatch(Http11Nio2Processor.java:155)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:650)
at
org.apache.coyote.http11.Http11Nio2Protocol$Http11ConnectionHandler.process(Http11Nio2Protocol.java:177)
at
org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.doRun(Nio2Endpoint.java:1087)
at
org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.run(Nio2Endpoint.java:1046)
at
org.apache.tomcat.util.net.Nio2Endpoint.processSocket0(Nio2Endpoint.java:598)
at
org.apache.tomcat.util.net.Nio2Endpoint.processSocket(Nio2Endpoint.java:583)
at
org.apache.coyote.http11.InternalNio2OutputBuffer$2.completed(InternalNio2OutputBuffer.java:199)
at
org.apache.coyote.http11.InternalNio2OutputBuffer$2.completed(InternalNio2OutputBuffer.java:165)
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
at sun.nio.ch.Invoker$2.run(Invoker.java:218)
at
sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
18-Feb-2015 15:51:17.183 FINE [http-nio2-127.0.0.1-8084-exec-10]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper@851105:org.apache.tomcat.util.net.Nio2Channel@406c4:sun.nio.ch.WindowsAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:8084 remote=/127.0.0.1:51890]], Status in:
[OPEN_WRITE], State out: [CLOSED]
]]]
The ISE is probably the one causing error 500. It is interesting to
note that there are many different threads involved.
Port 8084 is Nio2. My connectors configuration:
[[[
<Connector port="8081" address="127.0.0.1"
protocol="org.apache.coyote.http11.Http11Protocol"
connectionTimeout="20000"
redirectPort="8443" />
<Connector port="8082" address="127.0.0.1"
protocol="org.apache.coyote.http11.Http11NioProtocol"
connectionTimeout="20000"
redirectPort="8443" />
<Connector port="8083" address="127.0.0.1"
protocol="org.apache.coyote.http11.Http11AprProtocol"
connectionTimeout="20000"
redirectPort="8443" />
<Connector port="8084" address="127.0.0.1"
protocol="org.apache.coyote.http11.Http11Nio2Protocol"
connectionTimeout="20000"
redirectPort="8443" />
<Connector port="8443" address="127.0.0.1"
protocol="org.apache.coyote.http11.Http11Protocol"
maxThreads="150" SSLEnabled="true" scheme="https" secure="true"
clientAuth="false" sslProtocol="TLS"
sslEnabledProtocols="TLSv1,SSLv2Hello"
connectionTimeout="20000"
/>
<Connector port="9443" address="127.0.0.1"
protocol="org.apache.coyote.http11.Http11NioProtocol"
maxThreads="150" SSLEnabled="true" scheme="https" secure="true"
clientAuth="false" sslProtocol="TLS"
sslEnabledProtocols="TLSv1,SSLv2Hello"
connectionTimeout="20000"
/>
<Connector port="10443" address="127.0.0.1"
protocol="org.apache.coyote.http11.Http11Nio2Protocol"
maxThreads="150" SSLEnabled="true" scheme="https" secure="true"
clientAuth="false" sslProtocol="TLS"
sslEnabledProtocols="TLSv1,SSLv2Hello"
connectionTimeout="20000"
/>
]]]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
