ログにはあるのに利用者は知らない - オペレーターに語らせる

目標

2つのイベントAPIで、イベントを自分で作成して必須フィールドと集計を確認し、慣例に違反したときにツールからどう消えるかを見たうえで、イベントだけを読んで事故を再構成する表を作ります。

なぜ重要なのか

Operatorが何をしたかをユーザーが知れる場所は、3か所しかありません。コントローラーのログ、リソースのstatus、そしてイベントです。ログを見るのはクラスターの運用者だけで、statusは今の状態を語るだけで過程を含みません。ユーザーが実際に読む場所は、kubectl describeの下のほうのEventsだけです。そのため、Operatorを作る仕事の半分は、何をイベントとして残すかを決めることです。ただし、イベントはログではありません。デフォルトの保存期間は1時間で、同じ理由の繰り返しは新しいオブジェクトではなくcountの増加にまとめられ、APIが2つなのに保存先は1つです。この性質を知らずに、イベントに監査証跡を期待すると、いざ事故を調査するときに何も残っていません。

ステップ

/root/op-events/pipeline-crd.yamlにCRD pipelines.ev.labhub.ioを書いてください。グループev.labhub.io、kind Pipeline、複数形pipelines、バージョンはv1を1つで、スキーマにはspec.stage(string)だけを置きます。ネームスペースop-eventsを作成し、/root/op-events/pipeline-build1.yamlでPipeline build-1(stage build)を適用した後、そのmetadata.uidを/root/op-events/pipeline-uid.txtに1行で保存してください。
/root/op-events/event-started.yamlに、v1のEvent build-1-startedを書いてください。involvedObjectはPipeline build-1(apiVersion・kind・name・namespace・実際のuid)、reasonはReconcileStarted、typeはNormal、messageは1文、firstTimestampとlastTimestampは現在の時刻、countは1、source.componentはpipeline-operatorです。適用した後、kubectl -n op-events eventsの出力を/root/op-events/events-list.txtに保存してください。
/root/op-events/event-bad.yamlにEvent build-1-orphanを書きますが、involvedObjectをまったく入れません(reason NoTarget、type Normal、messageは1文)。適用を試みて、結果を/root/op-events/invalid-event.txtに集めてください。1行目はapply-rc=<종료 코드>(プレースホルダーは終了コードです)で、その下にサーバーが出した文をそのまま貼り付けます。
/root/op-events/event-weird.yamlにEvent build-1-weirdを書いてください。対象はPipeline build-1、reasonはStageUnknownで、typeは慣例外の値Criticalにします(時刻のフィールドは、ステップ2と同じ形式で埋めます)。適用した後、kubectl -n op-events events --types=Criticalとkubectl -n op-events events --types=Warningを順に実行して、結果を/root/op-events/type-report.txtに集めてください。2つのコマンドの出力と、それぞれの終了コード(critical-rc=、warning-rc=)が入っている必要があります。
ステップ2のイベントがさらに4回起きたと仮定して、集計フィールドを更新してください。kubectl -n op-events patch event build-1-started --type=mergeで、countを5に、lastTimestampを現在の時刻に変更します。そのあと、kubectl -n op-events eventsの出力を/root/op-events/count-report.txtに保存してください。
/root/op-events/event-done.yamlに、新しいAPI(events.k8s.io/v1)のEvent build-1-doneを書いてください。対象はregarding(Pipeline build-1、実際のuidを含む)、reasonはReconcileSucceeded、noteは1文、typeはNormal、eventTimeは現在の時刻(小数点以下6桁)、reportingControllerはpipeline-operator、reportingInstanceはpipeline-operator-0、actionはReconcileです。適用した後、2つのAPIでそれぞれ一覧を取り出して、/root/op-events/both-apis.txtに保存してください。core:で始まる行とnew:で始まる行が、それぞれkubectl get eventsとkubectl get events.events.k8s.ioの名前の一覧である必要があります。
/root/op-events/hungry-pod.yamlにPod hungryを書いてください。コンテナを1つ(app、イメージbusybox:1.36)置き、requests.cpuを"64"で要求します。適用して、スケジューラーがイベントを残すまで待った後、kubectl -n op-events get events --field-selector reason=FailedScheduling -o wideの出力を/root/op-events/scheduler-event.txtに保存してください。
/root/op-events/timeline.shを作成してください。op-eventsのすべてのイベントを、<type> <reason> <대상종류>/<대상이름>(プレースホルダーは順に、type、reason、対象のkind、対象の名前です)の1行ずつで出力しますが、ソートして重複を除きます。年齢・時刻・countのように、見るたびに変わる値は入れません。出力を/root/op-events/timeline.txtに保存し、その表だけを見て何があったかを/root/op-events/incident.txtに、人が読める文で書いてください。スケジューラーが残した理由とOperatorが残した理由の両方に言及する必要があり、慣例外のtypeが混ざっていることも指摘する必要があります。

参考

v1のEventは、involvedObject・reason・type・message・sourceを使います。
events.k8s.io/v1は、同じ場所をregarding・note・reportingControllerと呼びます。
typeの慣例は、NormalとWarningの2種類だけです。APIは強制しません。
kubectl eventsとkubectl describeは、同じイベントを別の形で表示します。
よくあるミス: reasonに長い文を入れて、集計できなくしてしまうことです。
よくあるミス: イベントを監査記録として使うことです。デフォルトの保存期間は1時間です。
参考: https://kubernetes.io/docs/reference/kubernetes-api/cluster-resources/event-v1/
参考: https://kubernetes.io/docs/reference/command-line-tools-reference/kube-apiserver/

イベントを付ける対象を作る

/root/op-events/pipeline-crd.yamlにCRD pipelines.ev.labhub.ioを書いてください。グループev.labhub.io、kind Pipeline、複数形pipelines、バージョンはv1を1つで、スキーマにはspec.stage(string)だけを置きます。ネームスペースop-eventsを作成し、/root/op-events/pipeline-build1.yamlでPipeline build-1(stage build)を適用した後、そのmetadata.uidを/root/op-events/pipeline-uid.txtに1行で保存してください。

イベントは、常に「あるオブジェクトについての話」です。そのため、対象のkind・名前・ネームスペースだけでなく、uidまで書いておかないと、同じ名前で作り直された別のオブジェクトの話と混ざってしまいます。uidは、次のステップでそのまま使います。

Operatorが最初の一言を残す

/root/op-events/event-started.yamlに、v1のEvent build-1-startedを書いてください。involvedObjectはPipeline build-1(apiVersion・kind・name・namespace・実際のuid)、reasonはReconcileStarted、typeはNormal、messageは1文、firstTimestampとlastTimestampは現在の時刻、countは1、source.componentはpipeline-operatorです。適用した後、kubectl -n op-events eventsの出力を/root/op-events/events-list.txtに保存してください。

reasonは、人が読む文ではなく、機械が数える鍵です。そのため、慣例は短いCamelCaseの1語で、同じ理由が繰り返されると、新しいイベントではなく1つにまとめられます。messageの側に、詳しい説明を入れてください。対象がカスタムリソースでも、kubectl describeの下のほうに、そのまま付きます。

対象のないイベントは作れない

/root/op-events/event-bad.yamlにEvent build-1-orphanを書きますが、involvedObjectをまったく入れません(reason NoTarget、type Normal、messageは1文)。適用を試みて、結果を/root/op-events/invalid-event.txtに集めてください。1行目はapply-rc=<종료 코드>(プレースホルダーは終了コードです)で、その下にサーバーが出した文をそのまま貼り付けます。

イベントは、対象があってはじめて意味が生まれます。対象がないと、どのオブジェクトのdescribeにも付けられず、一覧に理由だけが浮いてしまいます。そのため、APIが最初から拒否するのですが、エラーが正確にどのフィールドを指しているかを読むと、イベントと対象のネームスペースの関係も、一緒にわかります。

慣例外のtypeは、ツールから消える

/root/op-events/event-weird.yamlにEvent build-1-weirdを書いてください。対象はPipeline build-1、reasonはStageUnknownで、typeは慣例外の値Criticalにします(時刻のフィールドは、ステップ2と同じ形式で埋めます)。適用した後、kubectl -n op-events events --types=Criticalとkubectl -n op-events events --types=Warningを順に実行して、結果を/root/op-events/type-report.txtに集めてください。2つのコマンドの出力と、それぞれの終了コード(critical-rc=、warning-rc=)が入っている必要があります。

APIサーバーは、typeの値を検査しません。そのため、オブジェクトは何事もなく作られます。問題はその後で、イベントを読むツールは、NormalとWarningの2種類しかないと想定して作られています。慣例が強制されていないのに守るべき理由が、ここにあります。

同じ理由の繰り返しは、新しいイベントではない

ステップ2のイベントがさらに4回起きたと仮定して、集計フィールドを更新してください。kubectl -n op-events patch event build-1-started --type=mergeで、countを5に、lastTimestampを現在の時刻に変更します。そのあと、kubectl -n op-events eventsの出力を/root/op-events/count-report.txtに保存してください。

イベントレコーダーは、同じ対象・同じ理由・同じメッセージに再び出会うと、新しいオブジェクトを作らずに、この2つのフィールドだけを修正します。一覧の画面のLAST SEEN列が、そのときどう変わるかを、自分で見てください。括弧の中の表記が、このステップの答えです。調整ループが毎秒何回も回っても、etcdが破裂しない理由でもあります。

APIは2つなのに、保存先は1つ

/root/op-events/event-done.yamlに、新しいAPI(events.k8s.io/v1)のEvent build-1-doneを書いてください。対象はregarding(Pipeline build-1、実際のuidを含む)、reasonはReconcileSucceeded、noteは1文、typeはNormal、eventTimeは現在の時刻(小数点以下6桁)、reportingControllerはpipeline-operator、reportingInstanceはpipeline-operator-0、actionはReconcileです。適用した後、2つのAPIでそれぞれ一覧を取り出して、/root/op-events/both-apis.txtに保存してください。core:で始まる行とnew:で始まる行が、それぞれkubectl get eventsとkubectl get events.events.k8s.ioの名前の一覧である必要があります。

新しいAPIは、フィールド名が違います。involvedObjectがregardingに、messageがnoteに、sourceがreportingControllerとreportingInstanceに分かれました。ところが、保存される場所は同じなので、古いAPIでもそのまま見えます。古いAPIで見たときに、どのフィールドが空になっているかを確認すると、2つのスキーマの違いが目に入ります。

本物のコントローラーが残すイベントを受け取ってみる

/root/op-events/hungry-pod.yamlにPod hungryを書いてください。コンテナを1つ(app、イメージbusybox:1.36)置き、requests.cpuを"64"で要求します。適用して、スケジューラーがイベントを残すまで待った後、kubectl -n op-events get events --field-selector reason=FailedScheduling -o wideの出力を/root/op-events/scheduler-event.txtに保存してください。

このPodは、どのノードにも入れません。スケジューラーは、その事実をPodのstatusにだけ書くのではなく、イベントとしても残しますが、メッセージには「いくつのうちいくつが、なぜだめなのか」がそのまま入っています。人が原因を探すときに、実際に読む文がこれです。イベントが付くまでに数秒かかるので、条件付きのループで待ってください。

イベントだけを読んで、事故を再構成する

/root/op-events/timeline.shを作成してください。op-eventsのすべてのイベントを、<type> <reason> <대상종류>/<대상이름>(プレースホルダーは順に、type、reason、対象のkind、対象の名前です)の1行ずつで出力しますが、ソートして重複を除きます。年齢・時刻・countのように、見るたびに変わる値は入れません。出力を/root/op-events/timeline.txtに保存し、その表だけを見て何があったかを/root/op-events/incident.txtに、人が読める文で書いてください。スケジューラーが残した理由とOperatorが残した理由の両方に言及する必要があり、慣例外のtypeが混ざっていることも指摘する必要があります。

事故の調査でイベントが価値を持つ理由は、「誰が何について、どんな判断をしたのか」が1行ずつ残っているからです。ところが、デフォルトの保存期間が1時間なので、遅れて調べると何も残っていません。そのため、長く保管すべきものは、イベントではなく、statusの条件や、外部のストレージに送った記録でなければなりません。