EDAS で Java アプリケーションの高 CPU 消費を診断 - EDAS

Java アプリケーションの実行中に、Java 仮想マシン ( JVM ) プロセスが大量の CPU を消費する場合があります。この場合、Java アプリケーションのパフォーマンスが低下します。いくつかのツールまたはコマンドを使用して、問題を分析および診断し、JVM プロセスの CPU 使用率が高い原因を見つけ、問題を解決できます。

重要

このトピックには、サードパーティ製ツールに関する情報が含まれている場合があります。この情報は参照用です。Alibaba Cloud は、サードパーティ製ツールの性能と信頼性、およびこれらのツールに対する操作の潜在的な影響について、保証またはその他の形式のコミットメントを行うものではありません。

EDAS Agent の組み込みコマンドを使用した診断

ECS クラスタ内の Elastic Compute Service ( ECS ) インスタンスの場合、Enterprise Distributed Application Service ( EDAS ) は、JVM プロセスで CPU リソースを消費するスレッドと、スレッドのスタックトレース情報を表示します。これにより、JVM プロセスの CPU 使用率が高い原因を迅速に発見できます。

SSH を使用して、CPU を大量に消費するプロセスが存在する ECS インスタンスにログオンし、su - admin コマンドを実行して admin アカウントに切り替えます。次に、次のコマンドを実行して、CPU を最も多く消費する上位スレッドを表示します。デフォルトでは上位 5 つのスレッドが表示されます。

edas busy-threads

説明

edas busy-threads -h コマンドを実行して、コマンドの使用に関するヘルプを表示します。

次のサンプルコードは、システム出力の例を示しています。

09/28/19 22:57:07 [INFO] EXECUTING: busy-threads
[1] Busy(4.6%) thread(3222/0xc96) stack of java process(3221) under user(admin):
"main" #1 prio=5 os_prio=0 tid=0x00002ab68004e800 nid=0xc96 runnable [0x00002ab67c1df000]
 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:490)
  at org.apache.catalina.startup.Catalina.await(Catalina.java:819)
  at org.apache.catalina.startup.Catalina.start(Catalina.java:765)
  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:309)
  at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:443)
[2] Busy(0.9%) thread(2725/0xaa5) stack of java process(2721) under user(admin):
"DestroyJavaVM" #13 prio=5 os_prio=0 tid=0x00002ba81004c000 nid=0xaa5 waiting on condition [0x0000000000000000]
 java.lang.Thread.State: RUNNABLE
[3] Busy(0.0%) thread(3221/0xc95) stack of java process(3221) under user(admin):
[4] Busy(0.0%) thread(2721/0xaa1) stack of java process(2721) under user(admin):

次のサンプルコードは、一般的に使用されるパラメータとオプションの使用方法の例を示しています。

# 2 秒ごとに 5 回コマンドを実行します。デフォルトでは、JVM プロセスで CPU を最も多く消費する上位 5 つのスレッドが毎回表示されます。
edas busy-threads 2 5

# 指定された JVM プロセスで CPU を最も多く消費する上位 5 つのスレッドを表示します。[$JVM_PID] は、JVM プロセスの ID を示します。ps -ef |grep java を実行して、JVM プロセスの ID を表示できます。
edas busy-threads -p [$JVM_PID]

# JVM プロセスで CPU を最も多く消費する上位 10 個のスレッドを表示します。
edas busy-threads -c 10

# 過去 2 秒以内に大量の CPU を消費したスレッドを表示します。
edas busy-threads --current

オープンソースツールを使用した診断

show-busy-java-threads

非 ECS クラスタでは、show-busy-java-threads オープンソーススクリプトを使用して、指定されたプロセスで CPU を最も多く消費するスレッドを検出できます。次のコマンドを実行して、show-busy-java-threads スクリプトをダウンロードして使用します。スクリプトの使用方法の詳細については、「show-busy-java-threads」をご参照ください。

wget --no-check-certificate https://raw.github.com/oldratlee/useful-scripts/release/show-busy-java-threads
chmod +x show-busy-java-threads
./show-busy-java-threads

Arthas

上記のスクリプトに加えて、Alibaba が提供する Java 診断ツール Arthas を使用することもできます。このツールは、指定された JVM プロセスで CPU を最も多く消費するスレッドを表示することもできます。次のコマンドを実行して、現在接続されている JVM プロセスで CPU を最も多く消費する上位 3 つのスレッドとそのスタックトレース情報を表示します。

説明

Arthas 公式 Web サイトにアクセスして、Arthas をダウンロードしてください。

thread -n 3

次のサンプルコードは、システム出力の例を示しています。

"as-command-execute-daemon" Id=29 cpuUsage=75% RUNNABLE
  at sun.management.ThreadImpl.dumpThreads0(Native Method)
  at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440)
  at com.taobao.arthas.core.command.monitor200.ThreadCommand$1.action(ThreadCommand.java:58)
  at com.taobao.arthas.core.command.handler.AbstractCommandHandler.execute(AbstractCommandHandler.java:238)
  at com.taobao.arthas.core.command.handler.DefaultCommandHandler.handleCommand(DefaultCommandHandler.java:67)
  at com.taobao.arthas.core.server.ArthasServer$4.run(ArthasServer.java:276)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
  at java.lang.Thread.run(Thread.java:745)
  Number of locked synchronizers = 1
  - java.util.concurrent.ThreadPoolExecutor$Worker@6cd0b6f8
"as-session-expire-daemon" Id=25 cpuUsage=24% TIMED_WAITING
  at java.lang.Thread.sleep(Native Method)
  at com.taobao.arthas.core.server.DefaultSessionManager$2.run(DefaultSessionManager.java:85)
"Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@69ba0f27
  at java.lang.Object.wait(Native Method)
  - waiting on java.lang.ref.Reference$Lock@69ba0f27
  at java.lang.Object.wait(Object.java:503)
  at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)

従来の診断方法の使用

ホストがインターネットに接続されていない場合は、次の従来の方法を使用して、大量の CPU を消費するスレッドに関する情報を取得できます。次のコマンドを実行して、指定された JVM プロセスに関する情報を収集します。

top -Hbp [$JVM_PID] -d 1 -n 1 >> top.[$JVM_PID].txt && jstack [$JVM_PID] >> jstack.[$JVM_PID].txt

収集された top.XXX.txt ファイルで、CPU を最も多く消費するスレッドの ID を見つけます。top.XXX.txt のスレッドは、jstack.XXX.txt のスタックに対応しています。
次のコマンドを実行して、スレッドの 10 進数 ID を 16 進数に変換します。
```
printf %x [$Thread_ID]
```
説明
[$Thread_ID] は、手順 1 で見つけたスレッドの ID を表します。
jstack.XXX.txt でスレッドの 16 進数 ID を検索し、スレッドに関する情報を取得します。