https://bz.apache.org/bugzilla/show_bug.cgi?id=58646
--- Comment #24 from Alexander Malyshev <anmalys...@mail.ru> ---
I got some new info here.
1) This issue is hardly reproducible with the logs because logging for each
request highly slows down my server and request rate drops. I removed logs for
all request and now I'm only logging the scenario when processor is recycled
and put in RecycledProcessors map twice. And issue is reproducible very good
with such logging.
2) Here is what happens. In very rare cases processor is recycled twice. Here
is the info on how it gets recycled twice (note that I applied change from
Mark's last comment - It does not help at all). I'm remembering stack trace
line and thread name from last recycle call and if recycle is called once
again, I'm logging it out:
Feb 17, 2016 MSK 03:49:37.417 PM http-nio-135.60.87.68-443-exec-50
org.apache.coyote.http11.AbstractHttp11Processor
SEVERE: Exception!!! Processor with request 676 to URI /viewer/wcc/app.swf is
recycled twice.
First Calling method is:
org.apache.tomcat.util.net.NioEndpoint$Poller.cancelledKey(NioEndpoint.java:953)
by thread http-nio-135.60.87.68-443-exec-50
Current Calling method is:
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:785).
and right after that I'm getting usual NPEs and other exceptions related to
this processor:
Feb 17, 2016 MSK 03:49:37.425 PM http-nio-135.60.87.68-443-exec-46
org.apache.coyote.http11.Http11NioProcessor
INFO: Error parsing HTTP request header
Note: further occurrences of HTTP header parsing errors will be logged at
DEBUG level.. Request id: 676
java.lang.IllegalStateException: Unexpected state: headers already parsed.
Buffer not recycled?
at
org.apache.coyote.http11.AbstractNioInputBuffer.parseHeaders(AbstractNioInputBuffer.java:375)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1034)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:686)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1500)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1456)
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)
Feb 17, 2016 MSK 03:49:37.427 PM http-nio-135.60.87.68-443-exec-46
org.apache.coyote.http11.Http11NioProcessor
SEVERE: Error finishing response. Request id: 676
java.lang.NullPointerException
at
org.apache.coyote.http11.InternalNioOutputBuffer.flushBuffer(InternalNioOutputBuffer.java:234)
at
org.apache.coyote.http11.InternalNioOutputBuffer.addToBB(InternalNioOutputBuffer.java:189)
at
org.apache.coyote.http11.InternalNioOutputBuffer.commit(InternalNioOutputBuffer.java:177)
at
org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:748)
at org.apache.coyote.Response.action(Response.java:177)
at
org.apache.coyote.http11.AbstractOutputBuffer.endRequest(AbstractOutputBuffer.java:369)
at
org.apache.coyote.http11.AbstractHttp11Processor.endRequest(AbstractHttp11Processor.java:1818)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1157)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:686)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1500)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1456)
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)
Note that calling thread in both cases was http-nio-135.60.87.68-443-exec-50 -
which most probably means it happened during the same
AbstractConnectionHandler.process() call. I also noticed that it always happens
in the very begining of my traffic run and first time issue happens with the
request to static file (/viewer/wcc/app.swf). With the fact that one of the
possible call paths to cancelledKey() method is through
NioEndpoint.processSendfile() method - my opinion is that it's 90% related to
send file fucntionality and special logic for that.
--
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
