Hi Mark,
Thanks for the response - So far I've narrowed down to this;
0 - ntoskrnl.exe!KeSynchronizeExecution+0x2246
1 - ntoskrnl.exe!KeWaitForMultipleObjects+0x135e
2 - ntoskrnl.exe!KeWaitForMultipleObjects+0xdd9
3 - ntoskrnl.exe!KeWaitForSingleObject+0x373
4 - ntoskrnl.exe!KeStallWhileFrozen+0x1977
5 - ntoskrnl.exe!_misaligned_access+0x13f9
6 - ntoskrnl.exe!KeSynchronizeExecution+0x4133
7 - ntdll.dll!RtlCopyMemory+0x3
8 - WS2_32.dll!WSAPoll+0xb9
9 - tcnative-1.dll!Java_org_apache_tomcat_jni_Proc_detach+0xad10
10 - tcnative-1.dll!Java_org_apache_tomcat_jni_Poll_poll+0xac
>From what I can see there is one thread which is the main cpu user when
idle, it cycles through the above and;
jvm.dll!JVM_FindSignal+0x2cba
jvm.dll!JVM_ResolveClass+0x371c7
jvm.dll!JVM_ResolveClass+0x571d7
jvm.dll!JVM_MonitorWait+0xfe
jvm.dll!JVM_FindSignal+0x73f
Which looks to correspond to https-openssl-apr-8443-poller thread, which I
see cycling through RUNNABLE/TIMED_WAITING states (below are from when
there are zero requests occuring);
Name: https-openssl-apr-8443-Poller
State: RUNNABLE
Total blocked: 11,222,146 Total waited: 11,222,507
Stack trace:
org.apache.tomcat.jni.Poll.poll(Native Method)
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1675)
java.lang.Thread.run(Thread.java:745)
-------------
Name: https-openssl-apr-8443-Poller
State: RUNNABLE
Total blocked: 11,624,292 Total waited: 11,624,681
Stack trace:
org.apache.tomcat.jni.Poll.add(Native Method)
org.apache.tomcat.util.net.AprEndpoint$Poller.addToPoller(AprEndpoint.java:1449)
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1649)
java.lang.Thread.run(Thread.java:745)
------------------
Name: https-openssl-apr-8443-Poller
State: TIMED_WAITING on
org.apache.tomcat.util.net.AprEndpoint$Poller@4f5e5841
Total blocked: 12,441,180 Total waited: 12,441,614
Stack trace:
java.lang.Object.wait(Native Method)
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1573)
java.lang.Thread.run(Thread.java:745)
---------------------
Name: https-openssl-apr-8443-Poller
State: RUNNABLE
Total blocked: 13,278,363 Total waited: 13,278,853
Stack trace:
sun.misc.Unsafe.unpark(Native Method)
java.util.concurrent.locks.LockSupport.unpark(LockSupport.java:141)
java.util.concurrent.locks.AbstractQueuedSynchronizer.unparkSuccessor(AbstractQueuedSynchronizer.java:662)
java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1264)
java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:457)
java.util.concurrent.LinkedBlockingQueue.signalNotEmpty(LinkedBlockingQueue.java:176)
java.util.concurrent.LinkedBlockingQueue.offer(LinkedBlockingQueue.java:430)
org.apache.tomcat.util.threads.TaskQueue.offer(TaskQueue.java:74)
org.apache.tomcat.util.threads.TaskQueue.offer(TaskQueue.java:31)
java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1361)
org.apache.tomcat.util.threads.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:163)
org.apache.tomcat.util.threads.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:141)
org.apache.tomcat.util.net.AbstractEndpoint.processSocket(AbstractEndpoint.java:903)
org.apache.tomcat.util.net.AprEndpoint.processSocket(AprEndpoint.java:866)
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1731)
java.lang.Thread.run(Thread.java:745)
If I look at the 8080 poller thread (after load), it's waiting
appropriately.
I'll try and get the remote debugger connected now and see what time is
being passed for waiting.
On Wed, Jan 4, 2017 at 11:30 AM, Mark Thomas <[email protected]> wrote:
> On 04/01/2017 16:02, David Oswell wrote:
> > Hello all,
> >
> > wondering if anyone has seen similar behaviour - sorry if already
> reported,
> > googling hasn't found much other than a somewhat similar older issue on
> APR
> > going to 100% CPU when idle due to a poll loop/timeout issue - however
> this
> > seems a bit different as this is only occurring with SSL;
> >
> > Running (ESX Based):
> > Server version: Apache Tomcat/8.5.9
> > Server built: Dec 5 2016 20:18:12 UTC
> > Server number: 8.5.9.0
> > OS Name: Windows Server 2012 R2
> > OS Version: 6.3
> > Architecture: amd64
> > JVM Version: 1.8.0_112-b15
> > JVM Vendor: Oracle Corporation
> > Apache Tomcat Native library 1.2.10 using APR version 1.5.2.
> >
> > APR capabilities: IPv6 [true], sendfile [true], accept filters [false],
> > random [true].
> > APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
> > OpenSSL successfully initialized (OpenSSL 1.0.2j 26 Sep 2016)
> >
> > Server setup as 4 vCPU / 8GB mem
> >
> > Problem:
> > After running load on the server (this is a QA system, so just load
> tests)
> > Tomcat goes to 70-100% CPU usage when it should be idle.
> > This only occurs when putting load on the SSL connectors w/APR. When
> > re-applying load (to SSL connector), the CPU usage drops to appropriate
> > levels for the load, but then returns to the higher idle CPU usage.
> > If applying load back to the non-SSL connector, CPU usage stays high
> > (higher than after a restart and sending to non-SSL connector first).
> >
> > Performing the same load tests on non-SSL (still with APR), or non-APR
> > connectors CPU returns to idle after the load run is completed.
> >
> > The load applied is 8 persistent connections, which send basic POST
> > requests, the service does some basic operations and responds, generally
> -
> > if not maxed out - in 1-2ms.
> > Even when using 1 connection, the CPU usage stays constant when the
> > requests stop.
> > Again this only occurs when using the SSL/APR connector, if using a
> non-APR
> > connector, or the APR-non-SSL connector it's fine.
> >
> > It seems to be a problem with just how APR-SSL works or possibly OpenSSL
> ?
>
> An issue with the Tomcat code is more likely than with the OpenSSL code.
>
> It sounds like one or more threads is entering a fairly tight loop. Use
> a combination of top to find out which thread(s) is(are) using the CPU
> and then a thread dump to find where in the code it is happening.
>
> Then add a breakpoint at that point in the code, run your test and once
> the high CPU starts, attach your IDE and step through the code to see
> where/how the loop is happening.
>
> Instructions for running Tomcat under a debugger are on the Wiki.
>
> The more of the above you are able to complete, the simpler it is going
> to be to get this fixed.
>
> Mark
>
>
> > Not sure how to further isolate to see which one is the problem.
> >
> >
> > SSL Connector setup:
> > <Connector port="8443"
> > protocol="org.apache.coyote.http11.Http11AprProtocol"
> > maxThreads="150"
> > SSLEnabled="true"
> > maxKeepAliveRequests="-1">
> > <SSLHostConfig>
> > <Certificate
> > certificateFile="conf/localhost-rsa-cert.pem"
> > certificateKeyFile="conf/localhost-rsa-key.pem"
> > certificateKeyPassword="password"
> > type="RSA" />
> > </SSLHostConfig>
> > </Connector>
> >
> > Non-SSL Connector:
> > <Connector port="8080"
> > protocol="org.apache.coyote.http11.Http11AprProtocol"
> > connectionTimeout="20000"
> > maxKeepAliveRequests="-1"
> > redirectPort="8443" >
> > </Connector>
> >
> > Initializing ProtocolHandler ["http-apr-8080"]
> > Initializing ProtocolHandler ["https-openssl-apr-8443"]
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]
>
>
