2016-11-06 264 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虛擬機的內部部分。我無法確定,如果這是你的情況的問題。這可能是您正在閱讀的遠程系統的網絡問題或問題。我建議仔細看線程試圖找到一個模式。