https://bz.apache.org/bugzilla/show_bug.cgi?id=57592

            Bug ID: 57592
           Summary: numberwriter example: Response status 500,
                    asyncOperation() not valid for request with state
                    DISPATCHED
           Product: Tomcat 8
           Version: 8.0.18
          Hardware: PC
            Status: NEW
          Severity: normal
          Priority: P5
         Component: Connectors
          Assignee: dev@tomcat.apache.org
          Reporter: knst.koli...@gmail.com

First noted this when testing 8.0.20 release candidate,  but this is also
reproducible with 8.0.18 and 8.0.17.
http://markmail.org/message/rkkdl6publsievvi

Steps to reproduce:
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)

This issue depends on timing. E.g. it reproduces for me consistently with HTTP
connector, but not HTTPS connector. It does not reproduce in some other
configurations.

3) Add the following line to logging.properties to enable FINE logging for
Coyote:
org.apache.coyote.level=FINE

The following is observed in the log:
for Nio 2, Tomcat 8.0.20:

[[[
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]
]]]

For APR connector, Tomcat 8.0.20
[[[
18-Feb-2015 15:57:47.524 FINE [http-apr-127.0.0.1-8083-exec-6]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@1342088:86309568],
Status in: [OPEN_WRITE], State out: [LONG]
18-Feb-2015 15:57:47.529 FINE [http-apr-127.0.0.1-8083-exec-7]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@1342088:86309568],
Status in: [OPEN_WRITE], State out: [ASYNC_END]
18-Feb-2015 15:57:47.530 FINE [http-apr-127.0.0.1-8083-exec-7]
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.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:650)
    at
org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:285)
    at
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2439)
    at
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2428)
    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:57:47.536 FINE [http-apr-127.0.0.1-8083-exec-7]
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process
Socket:
[org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@1342088:86309568],
Status in: [OPEN_WRITE], State out: [CLOSED]
]]]

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

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

Reply via email to