On Tue, Jun 21, 2016 at 4:01 PM, Mark Thomas <ma...@apache.org> wrote:
> On 21/06/2016 13:43, Mark Thomas wrote:
>
>> I'll take a look at the code and see if I can figure out how this is
>> happening. Are you able to build 8.5.x from source to test any changes I
>> might make?
If all it needs is a Java tools, I can build.
Btw, tcnative is 1.2.7, the one that came in
apache-tomcat-8.5.3-windows-x64.zip.
>
> I have a theory which can be proved/disproved with some extra logging.
>
> First, please add the following line to logging.properties and then restart.
> org.apache.tomcat.util.net.AprEndpoint.level = FINE
>
> Re-create the problem and then look for the following in the logs. Where
> you see {n} in the message below, it will be replaced by some value.
>
> An APR general error was returned by the SSL read operation on
> APR/native socket [{0}] with wrapper [{1}]. It will be treated as EAGAIN
> and the socket returned to the poller.
>
>
> Do you see messages like this in the logs?
Restarted Tomcat and Firefox.
The following are just from loading the login form and its
dependencies (css/js).
21-Jun-2016 13:38:38.276 FINE [https-openssl-apr-8443-Acceptor-0]
org.apache.tomcat.util.net.AprEndpoint.processSocketWithOptions socket
[1,852,261,520]
21-Jun-2016 13:38:38.302 FINE [https-openssl-apr-8443-exec-1]
org.apache.tomcat.util.net.AprEndpoint.setSocketOptions Negotiated
[h2] protocol using ALPN
21-Jun-2016 13:38:38.303 FINE [https-openssl-apr-8443-exec-1]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [60,000], flags [1]
21-Jun-2016 13:38:38.303 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:38.304 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:38:39.272 FINE [https-openssl-apr-8443-Acceptor-0]
org.apache.tomcat.util.net.AprEndpoint.processSocketWithOptions socket
[1,852,286,144]
21-Jun-2016 13:38:39.287 FINE [https-openssl-apr-8443-exec-2]
org.apache.tomcat.util.net.AprEndpoint.setSocketOptions Negotiated
[h2] protocol using ALPN
21-Jun-2016 13:38:39.287 FINE [https-openssl-apr-8443-exec-2]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,286,144], timeout [60,000], flags [1]
21-Jun-2016 13:38:39.289 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,286,144]
21-Jun-2016 13:38:39.289 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,286,144] from poller
21-Jun-2016 13:38:40.020 FINE [https-openssl-apr-8443-Acceptor-0]
org.apache.tomcat.util.net.AprEndpoint.processSocketWithOptions socket
[1,852,294,352]
21-Jun-2016 13:38:40.041 FINE [https-openssl-apr-8443-exec-3]
org.apache.tomcat.util.net.AprEndpoint.setSocketOptions Negotiated
[h2] protocol using ALPN
21-Jun-2016 13:38:40.042 FINE [https-openssl-apr-8443-exec-3]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,294,352], timeout [60,000], flags [1]
21-Jun-2016 13:38:40.043 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,294,352]
21-Jun-2016 13:38:40.043 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,294,352] from poller
21-Jun-2016 13:38:40.549 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:38:40.649 FINE [https-openssl-apr-8443-exec-4]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:38:40.649 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:40.650 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:38:41.119 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,286,144] for event(s) [1]
21-Jun-2016 13:38:41.122 FINE [https-openssl-apr-8443-exec-6]
org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper.fillReadBuffer
An APR general error was returned by the SSL read operation on
APR/native socket [1,852,286,144] with wrapper
[org.apache.tomcat.util.net.
AprEndpoint$AprSocketWrapper@1dfa0278:1852286144]. It will be treated
as EAGAIN and the socket returned to the poller.
21-Jun-2016 13:38:41.125 SEVERE [https-openssl-apr-8443-exec-6]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Error
reading request, ignored
java.lang.IllegalStateException
at
org.apache.coyote.http2.Http2UpgradeHandler.fill(Http2UpgradeHandler.java:1087)
at
org.apache.coyote.http2.Http2UpgradeHandler.fill(Http2UpgradeHandler.java:1063)
at
org.apache.coyote.http2.Http2Parser.readConnectionPreface(Http2Parser.java:519)
at
org.apache.coyote.http2.Http2UpgradeHandler.init(Http2UpgradeHandler.java:225)
at
org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch(Http2UpgradeHandler.java:273)
at
org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:54)
at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785)
at
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2226)
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
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)
21-Jun-2016 13:38:41.134 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,286,144] from poller
21-Jun-2016 13:38:41.134 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint.destroySocket Destroying socket
[1,852,286,144]
21-Jun-2016 13:38:41.215 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,294,352] for event(s) [1]
21-Jun-2016 13:38:41.259 FINE [https-openssl-apr-8443-exec-7]
org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper.fillReadBuffer
An APR general error was returned by the SSL read operation on
APR/native socket [1,852,294,352] with wrapper
[org.apache.tomcat.util.net.
AprEndpoint$AprSocketWrapper@6132082:1852294352]. It will be treated
as EAGAIN and the socket returned to the poller.
21-Jun-2016 13:38:41.287 SEVERE [https-openssl-apr-8443-exec-7]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Error
reading request, ignored
java.lang.IllegalStateException
at
org.apache.coyote.http2.Http2UpgradeHandler.fill(Http2UpgradeHandler.java:1087)
at
org.apache.coyote.http2.Http2UpgradeHandler.fill(Http2UpgradeHandler.java:1063)
at
org.apache.coyote.http2.Http2Parser.readConnectionPreface(Http2Parser.java:519)
at
org.apache.coyote.http2.Http2UpgradeHandler.init(Http2UpgradeHandler.java:225)
at
org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch(Http2UpgradeHandler.java:273)
at
org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:54)
at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785)
at
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2226)
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
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)
21-Jun-2016 13:38:41.296 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,294,352] from poller
21-Jun-2016 13:38:41.296 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint.destroySocket Destroying socket
[1,852,294,352]
21-Jun-2016 13:38:42.212 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:38:42.214 FINE [https-openssl-apr-8443-exec-8]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:38:42.214 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:42.214 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:38:42.739 SEVERE [https-openssl-apr-8443-exec-9]
com.sun.faces.context.flash.ELFlash.getCurrentFlashManager JSF1094:
Could not decode flash data from incoming cookie value Invalid
characters in decrypted value. Processing will continue, but the
flash is u
navailable for this request.
21-Jun-2016 13:38:45.802 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:38:45.805 FINE [https-openssl-apr-8443-exec-10]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:38:45.805 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:45.806 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:38:45.990 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:38:46.002 FINE [https-openssl-apr-8443-exec-2]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:38:46.010 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:46.014 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:38:46.290 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:38:46.292 FINE [https-openssl-apr-8443-exec-4]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:38:46.294 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:46.294 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:38:46.416 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:38:46.417 FINE [https-openssl-apr-8443-exec-6]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:38:46.418 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:46.418 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:38:46.596 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:38:46.597 FINE [https-openssl-apr-8443-exec-8]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:38:46.597 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:38:46.597 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:39:45.084 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:39:45.085 FINE [https-openssl-apr-8443-exec-10]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:39:45.086 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:39:45.086 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:39:45.086 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:39:45.086 FINE [https-openssl-apr-8443-exec-2]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:39:45.087 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:39:45.087 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:40:43.088 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:40:43.090 FINE [https-openssl-apr-8443-exec-3]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:40:43.090 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:40:43.090 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:41:41.097 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:41:41.098 FINE [https-openssl-apr-8443-exec-1]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:41:41.098 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:41:41.098 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:41:47.018 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:41:47.024 FINE [https-openssl-apr-8443-exec-4]
org.apache.tomcat.util.net.AprEndpoint$Poller.add Add to addList
socket [1,852,261,520], timeout [-1], flags [1]
21-Jun-2016 13:41:47.027 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Add to poller socket
[1,852,261,520]
21-Jun-2016 13:41:47.027 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:41:47.027 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.run Processing socket
[1,852,261,520] for event(s) [1]
21-Jun-2016 13:41:47.028 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint$Poller.removeFromPoller
Attempting to remove [1,852,261,520] from poller
21-Jun-2016 13:41:47.028 FINE [https-openssl-apr-8443-Poller]
org.apache.tomcat.util.net.AprEndpoint.destroySocket Destroying socket
[1,852,261,520]
Thank you.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
