0時に寝て6時に起きた。

eks クラスター障害の原因判明

過去に2回発生していた eks クラスター障害 の原因がようやくわかった。テスト環境も本番環境は5日ごとに再現していて、datadog で k8s のダッシュボードでそれぞれの pod 単位のメモリ使用量をみると datadog-agent の pod がメモリリークしていることに気付いた。そこから当たりをつけて datadog-agent の issue を調べると次のバグに遭遇していた。

• [BUG] agent leaves defunct processes with version 7.38.0 #12997

ゾンビプロセスが生成されて、それが os のプロセス数上限に達してしまい、それによってプロセス (スレッド) が生成できなくなって、その結果として aws/amazon-vpc-cni-k8s の aws-node という eks クラスターの管理アプリケーションが動かなくなって、それが動かないと k8s ノードのステータスが NotReady になってしまって、通常の pod のアプリケーションも動かなくなってしまうという現象が発生していた。datadog-agent のアップグレードは私が行ったものだし、その後の k8s ノードの監視や調査で気付きが足りなかったと反省した。

• datadog-agent の新しいバージョンをテスト環境でもうしばらく検証してもよかった
• datadog-agent をリソースリークの可能性を私の中の調査対象から外していた
  • 世の中で使われているものに致命的なバグが起きないだろうという先入観があった
• プロセスを生成できない原因として考えられる背景を調査すべきだった
  • ulimit を確認してリソース制限はないようにみえた
  • プロセス数やゾンビプロセスを調べていなかった
  • kernel に /proc/sys/kernel/pid_max という上限設定があることを知らなかった
• テスト環境と本番環境で5日程度で落ちるという周期性から気付くべきだった
  • たしかにテスト環境から1日遅れて本番環境で障害が発生していた
  • 周期性があることでリソースリークの可能性は高いとすぐに調査すべきだった
• datadog で k8s のダッシュボードを調べるべきだった
  • すでに用意されているものがあったのでみようと思えばみえた
• aws のインフラ要因ではないかと疑っていた
  • ごめんなさい

これは悔しい。自分の無能さや気付きの低さを実感した事件だった。私が注意深く観察していればもう1週間早く気付けた。そのせいで余分な障害と調査に時間を費やした。1つ1つは全く難しくない現象が巧妙に絡みあって隠蔽された結果としての状況に気付けなかった。注意して1つずつ観察して追跡していけばすぐに気付けた。本当に悔しい。

1つだけ言い訳をさせてもらうと、私は本番環境にアクセスできない。だからテスト環境と本番環境で発生している現象が同じかどうかを判断できず、調査を進める確証をもてなかった。

呑み

あまりに悔しかったのと調査してたら遅くなって晩ご飯食べる気力もなかったので気分転換に仲のよい焼き鳥屋さんに寄ってみた。あとから常連客のセブンイレブンの店長さんも来られて、私は初対面かなと思ってたんだけど先方は知っていると言ってたから以前にもカウンターでご一緒していたみたい。何気はなしに3人で2時前ぐらいまで雑談していた。

その店長さんがロレックスを購入しようと考えているという話しになって、資産または投資商品としてのロレックスの話しになった。たまたまヒカキンが1億円で買ったロレックスがいま2億円になっているといった話しがあったそうで、いまがバブルな状態らしいが、ロレックスをはじめとした高級時計の資産価値が上がっているらしい。私は腕時計を身につけないし高級時計もまったく興味はないが、投資商品の1つなんだというところに関心がもてた。

中小企業の社長の一般的な節税方法の1つに外車を買ったり売ったりするという話しがある。儲かったときに経費で外車を買って、赤字のときに外車を売って雑所得に変える。車は社用車として経費で落とせるから可能なことだが、高級時計はどうなのだろうか？ 結論から言うと、普通の会社では高級時計は経費にできない。経費の原則は売上を上げるために必要な支出を経費とできる。普通の会社は高級時計で売上を上げることはできない。一方で経費として認められる職業もある。芸能人がそうだという。それは番組のために必要だという理屈で経費で落とせる。おそらくヒカキンも経費で高級時計を購入して、そのことを動画にしているのも仕事で必要だという言い訳作りの目的もあるのだと推測する。

1時に寝て5時半に起きた。

datadog のログアーカイブ

datadog には Log Archives という機能があって、datadog 経由でログをどこかのストレージに永続化できる。datadog プラットフォーム上では設定した期間内のログしか検索できず、おそらく料金の予算にあわせて期間を設定して、それが過ぎたら消えていくのだと思う。aws なら s3 に datadog に連携されたログをパイプライン処理してそのまま永続化できる。そのための s3 バケットの作成、s3 バケットへの datadog からのアクセス権限ロールの設定、datadog の aws インテグレーションの設定などをした。ドキュメントを読みながら1日あれば設定できたので難しくはない。もう cdk の設定にも慣れた感じで必要な権限を cdk の Stack としてコードで管理できるようにした。保守もばっちり。永続化されるログは gzip 圧縮されて時系列に s3 に永続化されるみたい。

23時に寝て4時半に起きた。昨日の帰りに自転車でこけて胸を強打してひたすら痛い。起き上がるのも痛い。安静にしてた。

kubernetes のログ管理と datadog-agent のログ連携不具合

先日、datadog にログ連携されていない不具合 が発生していて、その1次調査を終えたことについて書いた。緊急対応としては datadog-agent を再起動することで改善することはわかっていたので、その後、kubernetes のログ管理と datadog-agent がどうやって kubernetes クラスター上で実行されているアプリケーションのログを収集しているかを調査していた。今日は wiki に調査してわかったことなどをまとめていた。

kubernetes クラスターはコンテナランタイムに docker を使っていて、アプリケーションの stdout/stderr を docker の logging driver にリダイレクトし、JSON Lines に設定された logging driver が kubernetes ノード上にログファイルとして出力する。datadog-agent は autodiscovery 機能で pod の情報を常にポーリングしていて、pod が新たにデプロイされたらログファイルを pod 内にマウントして、そのマウントしたログファイルを読み込んでログ収集していると思われる。datadog-agent から pod の情報を取得するには kubernetes のサービスアカウントを使っていて、その credential が projected volume としてマウントされて pod 内から利用できる。その credential を使って kubelet api にリクエストすることで pod の情報を取得している。

文章で書けばたったこれだけのことなんだけど、たったこれだけのことを理解するのに次のドキュメントを読んだ。実際の調査のときはわからなかったのでもっと多くのドキュメントを読んでいる。いま書いたことを理解するならこのドキュメントを読めば理解できるはず。

• https://kubernetes.io/docs/concepts/overview/components/
• https://kubernetes.io/docs/concepts/architecture/control-plane-node-communication/
• https://kubernetes.io/docs/concepts/cluster-administration/logging/
• https://kubernetes.io/docs/tasks/configure-pod-container/configure-service-account/
• https://kubernetes.io/docs/concepts/storage/projected-volumes/
• https://docs.datadoghq.com/agent/kubernetes/log/?tab=helm
• https://docs.datadoghq.com/getting_started/agent/autodiscovery/?tab=kubernetes

ドキュメントに書いてあることを深く理解するために、kubernetes と datadog-agent のソースコードも読んだ。どちらも go 言語で実装されている。

• https://github.com/kubernetes/kubernetes
• https://github.com/DataDog/datadog-agent

kubectl logs の振る舞いを確認するだけでも、ソースコードからは実際のログファイルを open してストリームを返しているところはわからなかった。api 呼び出しが連携されて抽象化されていて、コンポーネントの役割分担があって、何も知らずにコードを読んでいてもわからなかった。Kubernetes の低レイヤーのところは Container Runtime Interface (CRI) という標準化を行い、1.20 から docker は非推奨となり、将来的に CRI を提供する実装に置き換わるらしい。ログファイルを open する役割は CRI の実装が担うんじゃないかと思うけど、そこまでは調べきれなかった。また機会があれば CRI の実装も読んでみる。

0時に寝て4時に起きた。朝から1時間ほどドラクエタクトやってた。

ログ連携の不具合調査

少し前に本番環境で datadog-agent からログが (クラウドの) datadog に連携されていないことがわかった。kubectl logs のコマンドで確認すると、アプリケーションのログは出力されているので datadog-agent から datadog にログを送信するところの問題であるように推測された。たまたま今日、同じような現象をテスト環境で確認できた。ちょうどスクラムのプランニングでログ調査のための作業をするチケットの承認を得たところだった。満を持して発生したような障害だったので私が調査すると明言して調査してた。半日ぐらい調査して、pod 内の credential 情報が置き換わってしまうことが原因っぽいと特定できたが、なぜ置き換わってしまうのかはまだわからない。もう少し調査して解決したら会社のテックブログにいいなと思ったので、日記に書いてた内容を移行することにした。

0時に寝て5時に起きた。昨日は早く寝たので早く起きた。

ふりかえり

お仕事でのスクラムのふりかえり。課題管理システムの一本化 や slack のマルチチャンネルゲスト移行 について、メンバーのよかったコメントがいくつか出た。私は経験者なので、これらの結果がどうなるかは最初からわかっていて、移行中に運用面からもあれこれプラクティスを提案しながら結果が出やすいようにサポートしていた。まだまだもっとうまく運用できるけれど、経験則では、他のメンバーの運用がついてくるには半年ぐらいかかるだろう。仕組みを取り入れただけではまだ効果が半分で、適切な運用を継続することでさらにその効果を実感できるようになる。これからも注力していく。

ともあれ、私がお手伝い始めた初日から非効率だと考えていた3大課題のうちの2つは2ヶ月経って対応された。ついでに書いておくと、最後の1つはカレンダー共有の課題がある。お手伝い先の社内で使っているカレンダーを協力会社のメンバーはみることができない。その逆も然り。したがって、正社員と協力会社でカレンダーを共有できない。これがスケジュール調整コストやコミュニケーションコストを高くしている。カレンダーを共有していると、例えば、slack でメンションして予定が入っていないならすぐに返信がくることを期待するけど、会議中だったらその会議が終わってからかな？といった予測が働く。仮に会議が3つ連続していれば、PR のレビューはすぐできないだろうと推測される。プロジェクトメンバーでカレンダーを共有できないと、相手の行動予測の精度が下がり、結果としてコミュニケーションコストが高くつく。

生産性をあげるには特別なことをやらなくても、当たり前のことを当たり前にしていくだけでも効果がある。同じ職場でずっと働いていると、当たり前じゃないことがわからなくなってしまって非効率になってしまうことも多々ある。そういうところは外部の人間が指摘することで改善できる余地となる。

datadog のログ管理

お仕事で datadog の ログ管理 機能を調べている。メトリクスしか使ったことがなかったけど、ログ管理も一通りの機能は揃っていていろいろできる。なぜか私が手伝う会社は datadog を使っていて、他のサービスも試してみたいという気持ちもあるんだけど、やっぱり datadog は優れたサービスということなのだろうか。