はじめに
エキサイト株式会社 バックエンドエンジニアの山縣(@zsp2088dev)です。
エキサイトホールディングス Advent Calendar 2022の25日目を担当します✍️
本記事では、SpringBootを使用したアプリケーションで、突然CPUがスパイクしてしまう事象に遭遇したことと、それを解決するために行ったことについて紹介します。
また、今回の事象を解決するにあたり、以下の記事を参考に調査を行いました。 blog.fastthread.io
システム概要
今回CPUがスパイクする問題が起きたのは、埋め込みリンクを作成するアプリケーションでした。
具体的には、はてなブログでも実装されているような、title
タグやmeta
タグをもとに、埋め込みリンクを作成するアプリケーションです。URLをもとに埋め込みリンクを作成する以外の機能はありません。
実行環境
アプリケーション
Azure Container Apps
- コア数:1.5
- メモリ:3Gi
- 最小レプリカ数:2台
- 最大レプリカ数:6台
- スケーリング:CPU使用率50%でスケールアウト
今回起きた事象
Azure Container Appsにて、最小レプリカ数2台、最大レプリカ数6台でアプリケーションを稼働しています。 アプリケーションの起動後、一定時間が経過すると、突然CPUがスパイクしてしまう現象が頻繁に起こっていました。 これは必ず起こるわけではなく偶発的に起こっており、図のとおり起動中のもう1台のコンテナは安定稼働していることが確認できます。
またCPUがスパイクすると、その後は再起動しないとCPU使用率が下がることはなく、スケールアウトしたままになってしまっていました。 そのため、GitHub Actionsで24時間に1度だけ再起動するようなワークフローを組んで対応していました。
解決手順
今回起きた事象に対して、以下の手順で解決しました。
- 起動中のコンテナに入る
- 起動中のJavaのプロセスID(PID)を取得する
- CPU使用率を調査する
- スレッドダンプを取得する
- スレッドダンプを解析する
- 原因箇所を特定する
起動中のコンテナに入る
Container Appsでは、対象のコンテナ > 監視 > コンソール より、コンテナに入ることができます。 原因調査のため、CPU使用率がスパイクしている本番環境のコンテナに入りました。
起動中のJavaのプロセスID(PID)を取得する
次に、下記コマンドを実行して、起動中のJavaのPIDを取得しました。
実際に実行すると、1
が取得できました。
ps aux | grep java
CPU使用率を調査する
top
コマンドを実行して、CPU使用率やメモリ使用率を取得しました。
上記で取得したPIDの1
を引数に渡して実行しました。
top -H -p <pid>
これにより、下記の結果を得ることができました。 ここで、CPU使用率99.3%のスレッドが立ち上がっていることが確認しました。 平常時に同様のコマンドを実行したところ、明らかに目立っているものはなかったため、これが原因であると推定しました。
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3093 root 20 0 47.6g 1.2g 878220 R 99.3 7.9 34:56.27 http-nio-8080-e 3073 root 20 0 47.6g 1.2g 878220 S 0.7 7.9 0:01.69 http-nio-8080-e 3088 root 20 0 47.6g 1.2g 878220 S 0.7 7.9 0:00.95 http-nio-8080-e 47 root 20 0 47.6g 1.2g 878220 S 0.3 7.9 0:05.58 http-nio-8080-e
スレッドダンプを取得する
より詳細な調査を行うために、スレッドダンプの取得をすることを検討しました。
そこで、コンテナ内でjstack
コマンドを実行して、スレッドダンプを取得しました。
jstack -l <pid> > result.txt
その後、コンテナ内のファイルをローカルPCに移動*1しました。
スレッドダンプを解析する
参考にした記事に従い、スレッドダンプの解析にfastThreadというサービスを使用しました。 fastThreadは、スレッドダンプを視覚的にわかりやすく表示してくれるサービスです。 PUBLICプランであれば無料で使用することができます。
ただし、以下のとおり書かれているため、PUBLICプランにて機密性の高いデータを扱うには注意が必要です。
In the 'Public' edition, your dumps are uploaded to the public cloud. For certain enterprises, it's a concern to upload production artifacts to the public cloud. In 'Enterprise' edition, application is privately installed and runs on your datacenter/local machine. Thus production artifacts will remain within your corporate firewall.
原因箇所を特定する
fastThreadを眺めていると、top
コマンドで見たPIDと同一のIDがあることを確認しました。
本アプリケーションは、ImageIO
を使用して画像加工を行っています。
ImageIO
は、主要な画像拡張子には対応していますが、faviconでよく使われるICOファイルには対応していませんでした。
そのため、ICOファイルの対応はサードパーティライブラリであるICODecoder
を使用するようにしていました。
どうやら今回のCPU使用率スパイクの原因となっていたのは、ICODecoder
である可能性が高いことがわかりました。
そこで、一時的にICOファイルの加工を行っている箇所を削除することで、様子を見ることにしました。
その後
原因となっていた箇所を削除してから1週間ほど経過しました。 アプリケーションは、平常時で0.1vCPU、高負荷時で0.3vCPUで稼働しており、無事に安定稼働していることがわかります。 対象箇所の代替となるライブラリの導入はできていませんが、今後調査をした上で再度実装したいと考えています。
振り返り
以上のとおり、スレッドダンプを解析することで、CPUがスパイクしてしまう問題を解決することができました。 本セクションでは、一連の流れを通して気になったことや、こうすればよかったと感じたことについて振り返りながらまとめます。
スレッドダンプからPIDを取得する
fastThreadを見るとOSのPIDである3093
が見つかりますが、スレッドダンプを全件検索しても3093
に該当する値を見つけることができませんでした。
これをどう算出しているのかが気になり、調べていたところ以下の記事にたどり着きました。
スレッドダンプから必要な情報のみを抽出すると、下記結果を得ることができます。
16進数の0xC15
は10進数で表すと3093
となり、これがPIDとなることがわかりました。
"http-nio-8080-exec-41" #3079 nid=0xc15
spring-boot-actuatorを使用してスレッドダンプを取得する
spring-boot-actuator
を使用すれば、jstack
の実行結果をローカルPCに送信する必要はなかったことに、執筆時に気づきました。
application.yml
にthreaddump
の設定を追加することで、/actuator/threaddump
にアクセスするとスレッドダンプを取得することができるようになります。
ただし、特に考えずに設定すると、グローバルに公開してしまう可能性があるため、IP制限を設けるなどの注意は必要です。
management: endpoints: web: exposure: include: threaddump
おわりに
SpringBootでCPUがスパイクする問題について、スレッドダンプを解析したことで原因箇所を特定することができました。 本記事がお役に立てれば幸いです。
参考記事
- HOW TO TAKE THREAD DUMPS? – 8 OPTIONS – Fast thread
- Troubleshooting CPU spike in a Major Trading Application – Fast thread
- スレッドダンプを解析する地獄とFastThreadというWebサービス - 理系学生日記
採用アナウンス
エキサイトではフロントエンジニア、バックエンドエンジニア、アプリエンジニアを随時募集しています。 また、長期インターンも歓迎しています。
カジュアル面談からもOKです。少しでもご興味がございましたら、お気軽にご連絡頂ければ幸いです。
▼ 募集職種一覧 ▼ recruit.jobcan.jp