2016-11-06 257 views
-1

我尝试了所有的事情来找到原因,但不知道什么是happing,试图jProfile,但它没有得到任何结果,因为cpu已经达到100%。Tomcat 100%CPU使用率

我在amazon linux上运行一个Spring应用程序(WAR文件),在 Tomcat8上运行。没有数据库操作,但是它访问运行在不同环境中的不同操作的休息api。 有3台服务器有一个负载平衡器豆杆后面运行相同的问题。平均每小时和72.2毫秒

我觉得平均延迟518K请求的没有太多的问题与代码本身

我只是尝试了命令kill -3 PID (java进程),并在catalina.out文件中获得了一些结果。我可以看到一次又一次以下错误

"http-nio-8080-exec-13" #42 daemon prio=5 os_prio=0 tid=0x00007f0898005800 nid=0xfb2 waiting on condition [0x00007f0882dec000] 
    java.lang.Thread.State: TIMED_WAITING (parking) 
    at sun.misc.Unsafe.park(Native Method) 
    - parking to wait for <0x00000000f1694f58> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) 
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) 
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) 
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85) 
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31) 
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) 
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) 
    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) 

"http-nio-8080-exec-18" #41 daemon prio=5 os_prio=0 tid=0x00007f088c024000 nid=0xfb1 waiting on condition [0x00007f0882eed000] 
    java.lang.Thread.State: TIMED_WAITING (parking) 
    at sun.misc.Unsafe.park(Native Method) 
    - parking to wait for <0x00000000f1694f58> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) 
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) 
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) 
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85) 
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31) 
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) 
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) 
    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) 

,并在年底的以下信息

"VM Thread" os_prio=0 tid=0x00007f08d8081000 nid=0xf8b runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f08d801e800 nid=0xf89 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f08d8020800 nid=0xf8a runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007f08d80f0000 nid=0xf92 waiting on condition 

JNI global references: 478 

Heap 
PSYoungGen  total 85504K, used 28368K [0x00000000fab00000, 0x0000000100000000, 0x0000000100000000) 
    eden space 83968K, 33% used [0x00000000fab00000,0x00000000fc61cd08,0x00000000ffd00000) 
    from space 1536K, 39% used [0x00000000ffd00000,0x00000000ffd97340,0x00000000ffe80000) 
    to space 1536K, 0% used [0x00000000ffe80000,0x00000000ffe80000,0x0000000100000000) 
ParOldGen  total 175104K, used 107142K [0x00000000f0000000, 0x00000000fab00000, 0x00000000fab00000) 
    object space 175104K, 61% used [0x00000000f0000000,0x00000000f68a1a48,0x00000000fab00000) 
Metaspace  used 56563K, capacity 60632K, committed 60800K, reserved 1103872K 
    class space used 5218K, capacity 5736K, committed 5760K, reserved 1048576K 

可能有人请解释这里发生了什么?

确定这里有一些我从日志这是在running状态拉动原木

(夫妇在日志时间)

"ajp-nio-8009-Acceptor-0" #23 daemon prio=5 os_prio=0 tid=0x00007f08d8535800 nid=0xfa0 runnable [0x00007f0883ffe000] 
    java.lang.Thread.State: RUNNABLE 
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) 
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) 
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) 
    - locked <0x00000000f0881618> (a java.lang.Object) 
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) 
    at java.lang.Thread.run(Thread.java:745) 

"ajp-nio-8009-ClientPoller-1" #22 daemon prio=5 os_prio=0 tid=0x00007f08d8534000 nid=0xf9f runnable [0x00007f08a83b2000] 
    java.lang.Thread.State: RUNNABLE 
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) 
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) 
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) 
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) 
    - locked <0x00000000f16a8100> (a sun.nio.ch.Util$2) 
    - locked <0x00000000f16a80f0> (a java.util.Collections$UnmodifiableSet) 
    - locked <0x00000000f16a7fc8> (a sun.nio.ch.EPollSelectorImpl) 
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) 
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1034) 
    at java.lang.Thread.run(Thread.java:745) 

"ajp-nio-8009-ClientPoller-0" #21 daemon prio=5 os_prio=0 tid=0x00007f08d82f8800 nid=0xf9e runnable [0x00007f08a84b3000] 
    java.lang.Thread.State: RUNNABLE 
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) 
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) 
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) 
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) 
    - locked <0x00000000f16a8900> (a sun.nio.ch.Util$2) 
    - locked <0x00000000f16a88f0> (a java.util.Collections$UnmodifiableSet) 
    - locked <0x00000000f16a87c8> (a sun.nio.ch.EPollSelectorImpl) 
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) 
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1034) 
    at java.lang.Thread.run(Thread.java:745) 

"http-nio-8080-Acceptor-0" #20 daemon prio=5 os_prio=0 tid=0x00007f08d82f7000 nid=0xf9d runnable [0x00007f08a85b4000] 
    java.lang.Thread.State: RUNNABLE 
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) 
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) 
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) 
    - locked <0x00000000f0882f68> (a java.lang.Object) 
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) 
    at java.lang.Thread.run(Thread.java:745) 

"http-nio-8080-ClientPoller-1" #19 daemon prio=5 os_prio=0 tid=0x00007f08d82f5800 nid=0xf9c runnable [0x00007f08a86b5000] 
    java.lang.Thread.State: RUNNABLE 
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) 
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) 
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) 
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) 
    - locked <0x00000000f1677900> (a sun.nio.ch.Util$2) 
    - locked <0x00000000f16778f0> (a java.util.Collections$UnmodifiableSet) 
    - locked <0x00000000f16777a8> (a sun.nio.ch.EPollSelectorImpl) 
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) 
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1034) 
    at java.lang.Thread.run(Thread.java:745) 

"http-nio-8080-ClientPoller-0" #18 daemon prio=5 os_prio=0 tid=0x00007f08d82f4000 nid=0xf9b runnable [0x00007f08a87b6000] 
    java.lang.Thread.State: RUNNABLE 
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) 
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) 
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) 
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) 
    - locked <0x00000000f1666290> (a sun.nio.ch.Util$2) 
    - locked <0x00000000f1666280> (a java.util.Collections$UnmodifiableSet) 
    - locked <0x00000000f1666138> (a sun.nio.ch.EPollSelectorImpl) 
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) 
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1034) 
    at java.lang.Thread.run(Thread.java:745) 

还有另外一道不知道其引起的问题(但只有一次登录)

"http-nio-8080-exec-131" #160 daemon prio=5 os_prio=0 tid=0x00007f088c100800 nid=0x153e runnable [0x00007f08727e5000] 
    java.lang.Thread.State: RUNNABLE 
    at java.net.SocketInputStream.socketRead0(Native Method) 
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) 
    at java.net.SocketInputStream.read(SocketInputStream.java:170) 
    at java.net.SocketInputStream.read(SocketInputStream.java:141) 
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) 
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:286) 
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345) 
    - locked <0x00000000f688f4d0> (a java.io.BufferedInputStream) 
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:704) 
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:647) 
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1536) 
    - locked <0x00000000f6892258> (a sun.net.www.protocol.http.HttpURLConnection) 
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1441) 
    - locked <0x00000000f6892258> (a sun.net.www.protocol.http.HttpURLConnection) 
    at sun.net.www.protocol.http.HttpURLConnection.getHeaderFields(HttpURLConnection.java:2966) 
    at com.code.http.WebUtility.getUrlContents(WebUtility.java:163) 

和th在此行E码是con.getHeaderFields(),那里的骗子是HttpURLConnection

try { 
    con = (HttpURLConnection) url.opencon(); 
    con.setDoInput(true); 
    con.setDoOutput(true); 
    con.connect(); 
    writeJson (con); 

    this.header = con.getHeaderFields();//this is the line in running state 
    this.code = con.getResponseCode(); 
    return readSuccessStream(con); 
} catch (IOException e) { 
    if (con != null) { 
     return readFailureStream(con); 
    } 
    return "a nasty error occured"; 
} finally { 
    if (con != null) { 
     con.disconnect(); 
    } 
} 

和其他一些胎面在运行状态

"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007f08d80db000 nid=0xf91 runnable [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f08d80c8800 nid=0xf90 waiting on condition [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f08d80bb000 nid=0xf8f waiting on condition [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f08d80b9000 nid=0xf8e waiting on condition [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

最后一个

"main" #1 prio=5 os_prio=0 tid=0x00007f08d8009800 nid=0xf88 runnable [0x00007f08de871000] 
    java.lang.Thread.State: RUNNABLE 
    at java.net.PlainSocketImpl.socketAccept(Native Method) 
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409) 
    at java.net.ServerSocket.implAccept(ServerSocket.java:545) 
    at java.net.ServerSocket.accept(ServerSocket.java:513) 
    at org.apache.catalina.core.StandardServer.await(StandardServer.java:446) 
    at org.apache.catalina.startup.Catalina.await(Catalina.java:717) 
    at org.apache.catalina.startup.Catalina.start(Catalina.java:663) 
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) 
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
    at java.lang.reflect.Method.invoke(Method.java:498) 
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:351) 
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:485) 
+0

要清楚,这些不是错误消息。那些是堆栈痕迹。 'kill -3'指示JVM为每个线程写入堆栈跟踪。它与来自异常的堆栈跟踪格式相同,但它不*表示正在抛出异常。它只是表明线程目前正在做什么。 – Brandon

+0

的确,这只是一种获取转储的方式,请阅读一些地方,我可以看到'java.lang.Thread.State:TIMED_WAITING(停放)'113次,这可能是一个原因吗? –

+1

@PHPAvenger不,这些线程只是在一个LinkedBlockingQueue.poll()调用(具有超时的那个)上阻塞。这不是CPU密集型的。 – Kayaman

回答

2

线程状态

在Java虚拟机一个线程的状态是:

NEW 
A thread that has not yet started is in this state. 

RUNNABLE 
A thread executing in the Java virtual machine is in this state. 

BLOCKED 
A thread that is blocked waiting for a monitor lock is in this state. 

WAITING 
A thread that is waiting indefinitely for another thread to perform a particular action is in this state. 

TIMED_WAITING 
A thread that is waiting for another thread to perform an action for up to a specified waiting time is in this state. 

TERMINATED 
A thread that has exited is in this state. 

在Java中,线程被表示为Thread对象(java.lang.Thread中)。当你创建一个新线程时,字面上与new Thread(),你创建一个线程,但它还没有做任何事情。一旦您致电Thread.start(),它将从NEW状态转变为RUNNABLE状态。可运行意味着它有未完成的CPU工作。在运行时,线程可以在RUNNABLE,BLOCKED,WAITINGTIMED_WAITING之间移动。当线程退出时,它将保留在TERMINATED状态中。

当试图通过Java进程诊断高CPU使用率时,我们可以排除NEWTERMINATED因为它们已经死亡的线程。一个线程BLOCKED,WAITINGTIMED_WAITING没有做任何事情。从字面上看,他们将来会等待一些事件。

这是什么意思?只有RUNNABLE状态中的线程才能将负载加载到CPU上。

这些线程是什么?

Tomcat使用一个线程池来同时处理多个请求。

这第一个线程是接受者线程。其目的是在网络套接字上侦听传入请求。但为了同时处理多个请求,它需要委托工作。否则,每个请求都会锁定服务器直到完成,这意味着一次只能有一个用户连接到Web服务器。所以这个线程简单地接受连接,然后把它们交给另一个线程,以便它可以接受更多的连接。

"http-nio-8080-Acceptor-0" #20 daemon prio=5 os_prio=0 tid=0x00007f08d82f7000 nid=0xf9d runnable [0x00007f08a85b4000] 
    java.lang.Thread.State: RUNNABLE 
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) 
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) 
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) 
    - locked <0x00000000f0882f68> (a java.lang.Object) 
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682) 
    at java.lang.Thread.run(Thread.java:745) 

这些线程到Tomcat的分配请求的工作线程:

"http-nio-8080-exec-13" #42 daemon prio=5 os_prio=0 tid=0x00007f0898005800 nid=0xfb2 waiting on condition [0x00007f0882dec000] 
    java.lang.Thread.State: TIMED_WAITING (parking) 
    at sun.misc.Unsafe.park(Native Method) 
    - parking to wait for <0x00000000f1694f58> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) 
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) 
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) 
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85) 
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31) 
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) 
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) 
    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) 

这意味着线程处于休眠状态。它正在等待接受者线程给它工作。它对您的100%CPU使用率没有贡献。

结论

的可运行的线程我在你的线程转储看到显示,从网络套接字读取是在CPU负载度过的。我无法明确地说出为什么。有两种可能的原因:网络或远程系统极其潜在的问题由于内存使用情况,读取是一个问题。

大部分时间,当我看到这个时,CPU工作来自垃圾收集器,它运行在另一个线程中。当分配内存的压力很小时,垃圾收集器在其他线程等待时需要花费很多昂贵的工作来查找可用内存。此线程可能在您显示的线程转储中不可见,因为它不是使用Java代码创建的线程,而是Java虚拟机的内部部分。我无法确定,如果这是你的情况的问题。这可能是您正在阅读的远程系统的网络问题或问题。我建议仔细看线程试图找到一个模式。