Kubernetesトラブル原因特定を容易にするロギング強化機能　富士通のエンジニアが考えたその課題と解決策

Request IDフラグ

長谷仁氏（以下、長谷）：ここから機能の紹介の中身になります。まずRequest IDフラグという、Request ID付与の有効／無効を制御する機能です。これをなぜ入れるのかというと、既存のログフォーマットを変えたくないユーザー向けとして、デフォルトではRequest IDの付与は今のところ無効にする予定で考えています。

次に有効／無効に関する制御の方式なんですけど、今は2つの方式が上がっていまして、どちらにするかは今コミュニティで議論中という状態です。1個目の方式がKubernetesの既存のログレベル機能「log verbosity」ですね。これを使うことを考えていて、log verbosityのレベルの-vオプションが4以上で、Request ID付与を有効にするという案です。

これのメリットとしては、ログに関係するようなフラグは、既存のものを使うので、フラグ管理の複雑化を避けれるというメリットがあります。一方でデメリットとして、Request IDを有効化したいがためにverbosityも大きくなるので、それと同時に出力されるログの情報も増えて、ログを格納するボリュームが増えるといった問題もあります。

2つ目の方式として、Request ID専用に新規フラグを作るという案もあるのですが、こちらについてはその分ログのフラグの種類が増えるので、管理がちょっと複雑になるデメリットもあります。今はどちらの方針にするかは、まだ議論中で決定しておりません。

どちらの方式も、各コンポーネントの起動時にログの初期化フェーズがあるのですが、そこに設定するような仕組みを考えていまして、設定変更する場合には、コンポーネントの再起動が必要になるという注意事項もあります。

設計上の課題

ここから設計上の今ある課題について説明していきます。先ほども少し話したのですが、実際に対象にするkubectlのサブコマンドは、いくつか限定しようと考えています。それはなぜかと言いますと、Request ID付与を実際にソースコード上で実装する場合に、ソースコード上の既存のログ呼び出し箇所ですね。

実際にKubernetesのログ呼び出しはklogを使って実現しているんですけど、各ソースコード上に散りばめられているklogの呼び出しを1つずつ書き換えていく作業が必要になってきます。Kubernetesのソースコードで、klogを使っている部分は10,000以上あるため、Request IDを付与するklogの呼び出し対象の優先度に基づいて限定しようと考えています。

ここにある表は、使用頻度の高いユーザー操作として優先度を書いています。まずはユーザー利用がもっとも多いPod操作として、create、delete、applyとか。対象リソースとしてPodやDeploymentを高優先度として考えています。あとはユーザーの資産を保存するPVとかPVCに対する操作としてcreate、delete、applyは変わらないですが、処理ソースとしてPVとかPVCとか。

あとはオーケストレーション系も、比較的トラブルの多いネットワーク関係でSVCとか、そういったコマンドを実行したときのログには、Request IDを付与しようかなと考えています。ここは利用者の操作優先度を検討して、段階的に対象範囲を拡大していこうと考えています。

2つ目の課題として、対象環境の選定がありまして、実際にその特定のコマンドを実行したときに呼び出されるklogは、環境によって差分がでてくる問題があります。

例えばコンテナのランタイムが違ったりボリュームタイプが違ったりすると、呼び出されるklogのソースコードが変わってくることもあり、このパターンに対して呼び出されるすべてのklogにRequest IDを付与すると、膨大な作業になる懸念があります。ここでは代表的な構成をいくつか挙げて、それに対するklogを対象にしようと考えています。

（スライド参照）コンテナランタイムやボリュームタイプとかネットワークプラグインを挙げていますが、他にもいくつかの要素を考慮して、代表的な構成でのklog呼び出しを対象にしようと考えています。

Request IDは2つの前提機能が存在

続きまして、このRequest ID機能には前提機能が2つあります。1つ目はStructured Loggingという機能で、これはGoogleが提案して今開発中の機能になります。これはどういったものかと言うと、Kubernetesのコンポーネントのログは現状テキスト形式なんですが、それを構造化のJSON形式に置き換えるというものです。

今コミュニティ上での議論では、Request IDを付けるのは、この構造化形式への移行後に実装するという話になっています。（スライドを示し）これはちょっと簡略化したログの例なんですが、左側にあるのが従来のテキスト形式でUpdated pod nginx-1 status to readyというのがあります。今後、この構造化がマージされたあとは、こういった感じのJSON形式になっていきます。

そのkeyとvalueのかたちで各要素を表現するものになってきます。この構造化形式の上にRequest IDを実装しようとしていまして、Request IDもJSONのそのkeyとvalueという値で付け加えようと考えています。この構造化形式でログがJSON化することで、ログの管理とかクエリの容易性は今後どんどん向上していくと考えています。

これがマージされるKubernetesのバージョンは、一応1.19と予定されていて、今開発中です。

個々のklogに手を加えるのは大変なので、対象を限定しますという話があったのですが、なぜそんなことをしているかを補足します。大元のklog定義やラッパーを使うことで、ここのklogに手を加える必要はないという考えもあると思いますが、そういったもうちょっと難しい理由について説明します。

まず前提条件としまして、klogは従来のテキスト形式から構造化形式に移行するという前提がありまして、Request IDでもこの構造化形式のkey、valueに則るかたちで考えています。この構造化に移行するには課題がありまして、実際にソースレベルでは、現状個々のklog呼び出しはテキストなので、これをkey、valueに分解する作業が必要になってきます。

（スライド参照）ここにあるのが例になります。従来では、ソースコード上ではklog.Infofというメソッドでテキスト形式で"Pod name %s is ready"がありますが、これを構造化にしようと思うと、.InfoSという新しいメソッドに置き換わって、最初の"Pod status update"は、これはテキストのメッセージなんですけど、そのあとにある"pod","pod","status","ready"はそれぞれkey、value、key、valueというかたちに置き換えられて、ソースコードを書くものになってきます。

このときにラッパーとかで対処しようと思うと、個々のテキストを適切なkeyとかvalueに自動選別するロジックが必要になってきます。しかし現状では、個々のメッセージのフォーマットは統一されていないので、どれをkeyにしてどれをvalueにするかは、どうしてもその人の目で見て判断する作業が必要になり、自動でラッパーを使って置き換えるような作業は現状困難になっています。

という事情もありまして、Request IDもこの構造化形式に乗っかるという議論になっているので、個別に対処が必要なので、対象とするkubectlのサブコマンドは限定しています。

トレース情報の伝播機能をRequest IDに活用

あとこのRequest ID機能には、もう1個前提機能がありまして、Distributed Tracingという機能があって、これは今Googleが提案している機能です。これの概要は、ユーザー操作のkubectl 〇〇というものに対してトレースを実現する機能です。

具体的には、--traceオプションをkubectlに付けることでトレースが可能になります。traceというのはkubectlコマンドの延長で、実際に各コンポーネントが動作しますが、それの処理を関数レベルで処理時間を計測できるようになるものです。

ここのどこがRequest IDの前提になるかと言いますと、トレース情報はコンポーネントをまたがって伝播していく動きになっていまして、この伝播する部分をRequest IDに活用しようと考えています。

具体的にはTracing機能では、KubernetesのオブジェクトのAnnotationにトレース情報を格納して、各コンポーネントの関数はオブジェクトにあるAnnotationのトレース情報を参照することによって、トレース情報をどんどん処理していく関数をコンポーネントに跨って伝播していくことが可能になってきます。ここの伝播する部分をRequest IDで活用しようと考えています。

このTracing機能の開発状況は、今は設計の承認待ちという状態です。当初はKubernetesの1.19で実装される予定でしたが、設計の承認が長引いてしまったがために、1.21以降になる見込みです。

Tracing機能がなぜ遅れたかという理由と、それに対するRequest IDの実装への影響について説明します。遅延理由としまして、Kubernetesのような各コンポーネントが独立して動いているアーキテクチャにおいて、コンポーネントを跨ったトレース方式の最適解がまだ確立できていません。コミュニティ上でアイデアはありますが、まだ正式な合意には至ってないというのが現状になります。

例えばRPCプロトコルに従うようなHTTP関連の伝播だと、kube-clientからkube-apiserverを経由してEtcdの範囲だったらこういった仕組みになっていて、その範囲であればHTTPのヘッダに情報を付与する、というかたちでトレースするのは実現できるんですが、大半のコンポーネントは独立駆動型のために、上記の方法は使えないのが現状です。

今はオブジェクトのAnnotationを使用するというアイデアもありますが、正式に承認が取れていないため、このTracing機能は、まずKubernetesの1.20ではHTTP周りの伝播のみで実装予定で、コンポーネント全体を伝播させるのは1.21以降になる見込みです。

Request ID機能への影響なんですけど、このTracing機能の伝播方式を利用する場合、必然的にTracing機能の実装と同じタイミングで1.21以降にずれる見込みになります。これがけっこう大きなブロッカーになってしまうため、現在Tracing機能に頼らない伝播方式を検討しています。

残課題と今後の予定

最後に残課題と今後の予定です。残課題として設計の合意、そしてRequest IDの有効／無効の制御方式とコンポーネント間の伝播方式については確立して承認をもらう必要があります。この承認が取れたら実際の実装に入るという予定になっています。その下の表が機能のロードマップで大きくα、β、GAと分けています。位置づけとして基本操作の実装、対応操作の拡充、あとは障害対応というようなフェーズに分けています。

α版では基本機能としてkubectlのcreate、apply、deleteとか、それに対するPod、Deploymentとか、あとはdrain nodeとかそういったものを対象にしようと考えています。β版ではその範囲をより広めていって、最後のGA版では上記に加えてコミュニティ上のフィードバックとかを反映しようと考えています。

これが最後のスライドになります。本セッションを聞いたKubernetesの運用者側への期待として、トラブルシュート時のログに関して困ったことがある方は、何でもいいのでフィードバックをお待ちしています。それによって、どんな機能を作ればいいかという参考にしたいなと思っています。あとは機能改善要望としてkubectlの別のサブコマンドとかリソースも対象にしてほしいという要望も歓迎します。

さまざまな運用者のニーズを把握することで、より価値のある機能にすることを狙いとしています。一方で開発者への期待としまして、Request IDの開発に興味をもたれた方は連絡をお願いしますということで、例えば共同で開発して、コンポーネントを跨る伝播方式をどうするかというアイデアも歓迎しています。

今たぶん日本国内でのKubernetesの運用者はすごく多いと思いますが、開発者の数はまだまだ少ないと思うので、日本での開発を盛り上げていきたいと考えています。連絡の際は、ここに3つぐらい連絡先が書いてあるので、どれでもいいので何か思うことがあれば連絡いただければなと思います。

発表は以上になります。ありがとうございました。

質疑応答

司会者：発表ありがとうございました。ではまだお時間がありますので、いくつか質問が来ていますので、私のほうで代理で質問いたします。まず1つ目なんですが、「Request IDは便利そうに感じました。今はLokiを使い始めているんですが、ログを横断的に解析するためのおすすめのツールはありますか？」という質問です。

長谷：おすすめのツールはサードパーティ製のOSSでいうと、先ほど挙げたたぶん代表的なFluentdとかElasticsearchとかKibanaとかで集めて、それにクエリをかければいいんじゃないかなと。現状ではまだそのくらいという感じですかね。

司会者：ありがとうございます。では2点目でKEPについてですね。KEPについて1点目で、「KEPを出す場合はGoogle Docsとかで事前にsigとディスカッションしているイメージが強かったのですが、KEPをまず提案するときのモックアップというか、KEPとして作った上でディスカッションしているのでしょうか？」というところです。

長谷：実態は、たぶん本当は事前にコミュニティとネゴ（ネゴシエーション）を取るべきだと思うんですけど、コミュニティ活動を始めたばかりで、そこら辺の事情をあまり考慮せずにいきなりKEPを出したんですよね。出したあとに「sigのミーティングにこんなKEPを出したので、説明するのでコメントをくれ」みたいなかたちでコミュニティミーティングに入っていく流れでやっていました。

司会者：なるほど。今感じる、本来こうしたらよかったみたいなものは、先にネゴしておけばよかったみたいなことでしょうか？

長谷：そうですね。

司会者：なるほど。ありがとうございます。もう1点ですね。「KEPを出す場合はチームで出す必要があるというのをどこかで見たんですが、今回は富士通さんのチームで出されたのでしょうか？　またはKEPを個人で出すことも可能なんでしょうか？」という質問です。

長谷：今回は富士通内のOSS開発チームでチームとして出しました。

司会者：「個人として出すことができるのか」ってご存知だったりしますか？

長谷：ちゃんと確認をしたことがないんですが、そういった制約があると思っていないですね。

司会者：わかりました。Slackとかでちょっと聞いてみてくださいという感じですかね。

長谷：そうですね。連絡先を書いているので、このGitのコメントというかたちでもいいですし。直接だとみんなが質問を見れないと思うので、一緒に開発したいという個人的な要望じゃない限りは、KubeFestのGitのコメントのほうが質問するにはいいと思います。

司会者：ありがとうございます。あと最後に自分のKEPに関してなんですが、出したときにこれを苦労したとか、sigのミーティングで説明する機会とかあったと思うんですけど、困ったこととかあります？

長谷：まず反応がありませんというのがありまして、これは去年の10月末ぐらいに出したんですけど、ちょっとコメントが付いたぐらいで反応が止まっちゃったので、「sigのミーティングで説明してあとでコメントするよ」って言っても返事が来なかったりとか苦労しました。

司会者：そうなんですね（笑）。

長谷：去年の11月ぐらいにKubeConサンディエゴがあったので、サンディエゴに行って直接レビューアの人とかに「例のKEPを出した者なんですけど」って突撃をして機能説明をして、そこから顔を覚えてもらってまたコメントをもらったりしていたんですけど、それでもレビューアの都合で返事がぜんぜん返ってこないということがけっこう続くので、そこは今苦労しています。

司会者：「心を強く」って感じですかね。

長谷：はい。

司会者：ありがとうございます。そういう意味だったらKubeConとかはそういう機会としてオフラインであるとやっぱりいいかもしれないですね。

長谷：エンジニア同士のつながりをもつという意味では大事だと思っています。

司会者：そうですね。ではお時間になりましたので以上になります。改めて発表ありがとうございました。