エンジニア

【K8s,Spring Boot】Datadogトレーサを追加したら永遠にLiveness Probeが成功しなくなった話

投稿日：2022.06.24更新日：2022.06.24

はじめまして。
Javaプログラマ兼K8s初心者の植木と申します。

最近業務でオンプレJavaアプリケーションをKubernetes(K8s)に移行する作業をしており、その中で直面した問題について1つご紹介したいと思います。

この記事で解説していること
・今回起きたこと
環境
Datadog
・トレーサを追加したらLiveness Probeが成功しなくなった話
・原因（設定内容の説明）
Readiness Probeの設定
Liveness Probeの設定
Resourcesの設定
PreStopの設定
TerminationGracePeriodSecondsの設定
原因（答え合わせ）
対策
深堀
補足
追記
まとめ
参考

この記事で解説していること

・ K8sのReadiness ProbeとLiveness Probeの仕組み（実例を元にして）
・ JavaアプリケーションをK8sで動かすために注意するポイント（上記に関連して）

なお、今回の記事を執筆するにあたりデモ用にコードを書き直しました。書いたコードは以下に置いてあります。

・ Javaコード(https://github.com/uekiGityuto/springboot-demo)
・K8sのマニフェスト (https://github.com/uekiGityuto/k8s-demo)

・今回起きたこと

オンプレJavaアプリケーションをK8sに移行するために、Javaアプリケーションを書き換えたり、K8sのマニフェストファイルを新規作成していたりしました。
ひとまずK8sでアプリが動くようになったので、DatadogというモニタリングツールにAPMを表示させるべく、Datadogのトレーサを追加したら、それまで成功していたLiveness Probe（死活監視）が成功しなくなったというのが今回起きたことです。

では、細かな用語も踏まえて解説していきますね。

環境

以下の環境でデモ用のコードを書いて動かしました。

・言語：Java 17
・フレームワーク：SpringBoot 2.7.0
・実行環境：Minikube（ローカル環境でKubernetesを実行するツール）

Datadog

今回導入したかったAPMについて少し触れておきます。

APMとはApplication Performance Managementの略称で、CPU、メモリ、レイテンシ、Javaランタイムメトリクス（ヒープやGC等）などをモニタリングする機能であり、Datadogにもこの機能があります。

DatadogではJava起動時、-javaagentオプションにdd-java-agent.jarを指定することでAPMを表示させることが出来ます。（他にDatadog Agentの導入などが必要ですが、今回のテーマとは関係ないので省略します）

-javaagentオプションで指定したJarは、本来実行したいJarの前に実行することが出来るので、
dd-java-agent.jarで本来実行したいJarの実行コードに変更をいれて、Datadogにデータを送信出来るようにしているようです。

・トレーサを追加したらLiveness Probeが成功しなくなった話

・事象
さて本題です。冒頭でも軽く触れましたが、もう少し詳しく事象を説明していきます。

私たちはまず、トレーサを追加しない状態でk8s上でアプリケーションを起動しました。（Datadog Agentも導入済み）
この時はReadiness Probe、Liveness Probeともに問題なく成功しました。

なお、詳しくは後述しますがReadiness ProbeとLiveness ProbeはK8sの機能の一つで、アプリケーションの起動監視、死活監視のようなものです。

その後、トレーサを追加して、APMを表示出来るようにしたのですが、なぜかLiveness Probeが失敗し続けるようになりました。（Liveness Probeは一定時間毎に定期的に実行されます）
なお、Readiness ProbeはアプリケーションログやAPMから成功を確認出来ていました。

Liveness Proveが失敗すると、K8sはアプリケーションが異常な状態であると判断し、アプリケーションを再起動（正確にはコンテナを再起動）させます。
今回はLiveness Proveが失敗し続けていたので、コンテナもフェニックスの如く消滅と復活を繰り返していました。（つまり、永遠に正常に起動しない状態でした。）

・原因（設定内容の説明）

結論から記載しますと、原因はK8sのマニフェストファイルの設定内容にありました。

この時のK8sのマニフェストファイルを一部抜粋します。（正確にはデモ用に書き換えたマニフェストファイルです）

Readiness Probeの設定

Liveness Probeの設定

Resourcesの設定

PreStopの設定

TerminationGracePeriodSecondsの設定

また、今回のデモではJavaのヒープサイズを指定していません。指定しない場合、コンテナのメモリサイズの1/4を使用します。（本来は使用すべきですが、今回は簡略化のため書略しています）

さていかがでしょうか。

上記の設定のどこかに原因があるのですが、分かりますでしょうか？

まどろっこしくて申し訳ございませんが、答え合わせの前に上記設定内容の説明をさせて下さい。

Readiness Probeはアプリケーションの準備が整っているかどうかを確認します。

今回の場合、/actuator/health/readinesにリクエストして200が返ってくれば準備OKと認識します。(※1)

逆に200が返ってこなかった場合は、1秒おき（periodSecondsで定義された秒数）にチェックを繰り返します。

Liveness Probeはアプリケーションが生きているかを確認します。（※2）

今回の場合、/actuator/health/livenessにリクエストして200が返ってくれば生きていると認識します。(※1)

逆に200が返ってこなかった場合は、1秒おき（periodSecondsで定義された秒数）にチェックを繰り返して、一定回数チェックしても200が返ってこない場合はコンテナを再起動させます。
チェック回数はfailureThresholdで定義していて、今回は1なので、1回でも失敗したら即再起動させます。

また、initialDelaySecondsで初回チェックまでの待機時間を決めています。

まとめると今回の場合、コンテナが起動してから10秒後に/actuator/health/livenessにリクエストして200が返ってくればOK、返ってこなければコンテナを再起動させます。

ResourcesはPodのCPUやMemoryの設定です。

Podとは簡単に記載すると、アプリケーションが起動するためにK8sから割り当てられたHostマシンの一部分のことです。
最低でもrequestsのresourceが確保され、Nodeのresourceに余裕があればlimitまで利用可能です。

また、ヒープサイズはコンテナのメモリサイズの1/4となるため、500Miの時は125m、1000Miのときは250mのヒープが利用できます。（本来はヒープサイズを指定すべきですが、今回は簡略化のため省略しています。）

PreStopはコンテナを停止させる前に実行される処理です。

今回の場合、コンテナ停止前に10秒間sleepします。
K8sはPodを停止する時に新規リクエストを停止対象のPodにルーティングしないようにサービスアウトします。
サービスアウトしてから、コンテナを停止出来るように10秒間のsleepをしています。

TerminationGracePeriodSecondsはコンテナが停止するまでの猶予期間です。

K8sはコンテナを停止させるとき、TerminationGracePeriodSecondsで設定した秒数だけ待機した後にコンテナを終了させます。

もう少し詳しく説明しますと、K8sはTerminationGracePeriodSecondsで設定した秒数を元に、削除予定時刻を設定します。

削除予定時刻が設定されたら、PreStopで設定した処理が実行され、その処理が終わったら、SIGTERMというシグナルをコンテナに送信します。

コンテナ側はSIGTERMを受信したら、処理を正常に終了させるのですが、もし削除予定時刻までに処理が終了しなければ、K8sはSIGKILLを送信してコンテナを強制終了させます。

なお、SIGTERMやSIGKILLはK8s独自の機能ではなく、Linux標準の機能です。
Linuxにkillコマンドがありますが、これはプロセスに対してSIGTERMやSIGKILLを送信しています。

原因（答え合わせ）

引き延ばして申し訳ございません。答え合わせしますね。

Liveness Probeが失敗するようになった原因は、ずばり、トレーサ追加により、アプリケーションの起動時間が伸びて、起動前にLibeness Proveを実行してしまっていたからでした。

トレーサは以下のようにjavaagentオプションで指定します。

`java -javaagent:/path/to/the/dd-java-agent.jar -jar ./demo.jar `
このオプションで指定されたJARファイルはjarオプションで指定されたJARファイルよりも前に起動するので（※4）、実際のアプリケーションの起動はその分遅くなります。

実際、トレーサ追加前は8秒程度だった起動時間が、追加後は15秒程度になっており、Liveness ProbeのinitialDelaySecondsに設定していた10秒を超えてしまったので、アプリケーション起動前にLiveness Probeが実行されてしまったというわけです。

対策

対策は以下の2つです。

・ Liveness ProbeのinitialDelaySecondsを伸ばす
・Resourcesを増やす

1つ目は分かりやすいと思います。

10秒では足りないので伸ばせば解決します。今回は30秒に伸ばしてみました。(※3)

2つ目はそもそもJavaアプリケーションを動かすにあたり、定義しているCPUやMemoryが小さすぎました。

今回はResourcesを以下のように修正したところ起動時間が8秒になりました。(※3)
K8sはGoのサンプルが多いのですが、Goに比べてJavaはCPUやMemoryを多く必要とするので、注意が必要です。

深堀

答え合わせをしたところで、次に、なぜLiveness Probeは失敗していたのに、Readiness Probeは成功していたのかを深堀したいと思います。
以下に今回の事象を時系列で整理しました。

1.    コンテナ作成 & Spring Boot起動：15秒間

2.    Readiness Probe失敗： 15秒間
※initialDelaySecondsの設定がないのでコンテナ作成後すぐ実行される

3.    Liveness Probe失敗

4.    PreStopHook起動（10秒間sleepし、sleep後にSIGTERM送信）

5.    Spring Boot起動完了
※コンテナ作成から15秒後

6.    Readiness Probe成功← 1秒おきに繰り返しているのでSpring Boot起動直後に成功する

7.    K8sからSpringBootにSIGTERM送信
※preStopHook起動から10秒後

8.    SpringBootでGraceful　Shutdown
※仕掛中のリクエストはあったとしてもReadiness ProbeのリクエストしかないのですぐにShutdownする

9.    コンテナ再作成（SpringBoot再起動）

つまり、Liveness Probe失敗とPod停止の間にタイムラグがあるので、その間にSpringBootが起動し、Readiness Probeが成功したということです。

なお、もし上記の8（Graceful　Shutdown）で、仕掛中リクエストの処理に時間がかかった場合は、Liveness Probe失敗からTerminationGracePeriodSecondsで設定した秒数経過後にSIGKILLが送信され、強制的にShutdownさせられます。（つまり、SIGTERM送信から20秒後に強制終了）

補足

※1：正確には200以上400未満であればOKと認識します。

※2：正確にはリクエストが処理できるか（デッドロックのような再起動しなければ回復不能な状態になっていないか）を確認します。

※3：実際には負荷試験でチューニングする必要があります。

※4：正確にはjarオプションで指定されたJARファイルのmainの前に、javaagentオプションで指定されたJARファイルのpremainが呼び出されます。

追記

この記事をJava + K8sの有識者の方に見て頂いたところいくつか指摘がありましたので、補足致します。

- ヒープサイズを正しく設定していれば、元々のresourcesの設定で、トレーサを追加しても10秒以内に起動するはずです。今回は簡略化のため、ヒープサイズを指定していなかったので、10秒以内に起動しませんでした。
- SpringBootのGraceful Shutdownを利用しているのであれば、PreStopで/actuator/shutdownエンドポイントを叩くのが一般的のようです。

まとめ

最後に今回のまとめをしたいと思います。
手短にまとめますのでもう少しお付き合い下さい。

今回、Datadogのトレーサを追加したことで問題が発生したので、Datadogのトレーサに原因があるのではないかと思い、最初はDatadogに焦点を当てて調査していました。
ただ、いくら調べてもDatadogに問題は見つからず、途方に暮れました。

実際、Spring Boot起動前にLiveness Proveが実行されていたという非常にシンプルな原因だったわけですが、これはJava（特にSpring Boot）の基礎的な知識（起動に必要な時間やCPU、Memory等）とK8sの基礎的な知識（Liveness Proveの仕組み等）が分かっていればすぐに解決出来た問題でした。
また、Linuxの基礎的な知識（SIGTERMやSIGKILL等）も必要でした。

これらを踏まえて感じたことは、表面的な知識（JavaのコーディングやK8sのマニフェストファイルの書き方等）が分かっているだけでは問題が起きた時に解決することは難しく、基礎的な知識をもっと深めていくべきだということです。

今回の問題を通して色々と勉強することが出来たので、これをきっかけに基礎的な知識を身に着けていこうと思いました。

以上です。お読み下さりありがとうございました。