sirupsen

klog, zap, logrus などで stderr に吐かれるログのレベルを Datadog で良い感じにする こんにちは、@key60228 です。 新しく立ち上げた GKE Cluster に Datadog Agent を入れてログを有効化してみたところ、とんでもない数のエラーログが吐かれていました。 まだ何も特別なことをしていないのに…？？？と不思議に思いログの詳細を見てみたところ、特に問題なさそうなログがほとんどでした。 結論としては、各コンポーネントが吐くログが Datadog が解釈できる形式で構造化されておらず、エラーレベルとして判定されてしまっていることが原因でした。 というわけでこの記事では各コンポーネント、ロガーがどんな構造で出力していて、どうすれば正しいログレベルで表示できるのかについてまとめていければと思います。 ソリューションを求めている方へ Datadog のログパイプラインで加工してあげてください。 Terraform pipelines.tf resource "datadog_logs_custom_pipeline" "container_log_level" { name = "container-log-level" description = "stderr 由来で error になったコンテナログの status を、本文の klog / zap / logfmt のレベルから付け直す。" is_enabled = true filter { query = "kube_cluster_name:*" } processor { grok_parser { name = "klog / zap / logfmt からレベルを取り出す" is_enabled = true source = "message" samples = [ "I0911 07:22:25.408586 1 cni_writer.go:930] Successfully synced \"gke-xxxxx-xxxxx-nod-xxxxxxxx-xxxx\"", # klog (GKE cni-writer) "E0911 07:10:07.225293 1 base_controller.go:161] \"controller failed to sync\" err=\"...\" key=\"image-sync\"", # klog (OCM work-agent) "2026-09-11T07:19:45Z\tINFO\tcontrollers.Spoke\trequeueing\t{\"request\": {\"name\":\"xxx\",\"namespace\":\"fleetconfig-system\"}, \"after\": \"1m0s\"}", # zap console、タブ区切り (fleetconfig-controller) "2026-09-11T04:39:22.159Z error logging/logging.go:16 NodeCollector: Failed to export metrics {\"kind\": \"receiver\"}", # zap console、スペース区切り (gke-metrics-agent) "time=2026-09-11T06:13:28Z level=info msg=Reconciling subsys=sfc reasons=[...]", # logfmt / logrus (cilium) ] grok { support_rules = "" match_rules = file("${path.module}/grok/container_log_level.grok") } } } processor { lookup_processor { name = "klog の severity 1 文字をレベル語に直す" is_enabled = true source = "klog.severity" target = "level" lookup_table = [ "I,info", "W,warning", "E,error", "F,critical", ] } } processor { lookup_processor { name = "zap のレベルを status remapper が解釈できる語に直す" is_enabled = true source = "zap.level" target = "level" lookup_table = [ "DEBUG,debug", "INFO,info", "WARN,warning", "ERROR,error", "DPANIC,critical", "PANIC,critical", "FATAL,critical", ] } } processor { lookup_processor { name = "logrus のレベルを status remapper が解釈できる語に直す" is_enabled = true source = "logfmt.level" target = "level" lookup_table = [ "trace,debug", "debug,debug", "info,info", "warning,warning", "error,error", "fatal,critical", "panic,critical", ] } } processor { status_remapper { name = "level を status にする" is_enabled = true sources = ["level"] } } } grok/container_log_level.grok klog %{regex("[IWEF]"):klog.severity}%{regex("\d{4} \d{2}:\d{2}:\d{2}\.\d+")}\s+%{integer:klog.thread_id}\s+%{regex("[^\]]+"):klog.location}]\s?%{data:klog.message} zap %{regex("\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d+)?(Z|[+-]\d{2}:\d{2})"):zap.timestamp}[\t ]+%{regex("(DEBUG|INFO|WARN|ERROR|DPANIC|PANIC|FATAL|debug|info|warn|error|dpanic|panic|fatal)"):zap.level:uppercase}[\t ]+%{data:zap.message} logfmt_with_time time=%{notSpace:logfmt.time}\s+level=%{word:logfmt.level:lowercase}\s+%{data:logfmt.message} logfmt level=%{word:logfmt.level:lowercase}\s+%{data:logfmt.message} Datadog Log Management のログレベルの仕組み Datadog のログでは status という予約済み属性が Log Explorer で表示されるログレベルに対応しています。1 Datadog Agent を使っている場合、この status は次の3つのタイミングで決まります。 Datadog Agent がログを送る時 Datadog が JSON ログをパースする時 ログパイプラインの Status Remapper を通る時 ① Datadog Agent がログを送る時 Kubernetes の Datadog Agent (各ノードの DaemonSet) では stdout に出たものを info、stderr に出たものを error と判定して Datadog に送っているようです。 github.com/DataDog/datadog-agent/blob/f85c4980d2b… ② Datadog が JSON ログをパースする時 次に、ログが JSON 形式であれば、Datadog は取り込み時の前処理で status、severity、level などの属性を探し、見つかった値で status を上書きします。2 {"level":"info","msg":"..."} のようなログは、stderr に書かれていても info として扱われます。 ③ ログパイプラインの Status Remapper を通る時 最後に、ログパイプライン に Status Remapper を置くと、任意の属性の値で status を上書きできます。 Status Remapper は指定された属性の値を先頭の文字列で以下の通り判定してくれます。3 値 status 0 から 7 の整数 Syslog の規格に従う emerg または f で始まる文字列 (大文字小文字を区別しない) emerg (0) a で始まる文字列 (大文字小文字を区別しない) alert (1) c で始まる文字列 (大文字小文字を区別しない) critical (2) err で始まる文字列 (大文字小文字を区別しない) error (3) w で始まる文字列 (大文字小文字を区別しない) warning (4) n で始まる文字列 (大文字小文字を区別しない) notice (5) i で始まる文字列 (大文字小文字を区別しない) info (6) d、t、v、trace、verbose で始まる文字列 (大文字小文字を区別しない) debug (7) o または s で始まる文字列、または OK か Success に一致する文字列 (大文字小文字を区別しない) OK 上記以外 info (6) つまり、プレーンテキストの本文にレベルを埋め込んでいるログは、②の前処理では拾われず、③のパイプラインを用意しない限り①のストリームだけで status が決まります。 今回の自分の環境のエラーログは、まさにこのパターンでした。 対策と各コンポーネント/ロガーの仕組み 根本的には各コンポーネントが JSON でログを吐くか、レベルに応じて stdout/stderr を使い分けていればこういった問題は起きません。 しかし GKE が管理するシステムコンポーネントは出力形式をこちら側では変えられず、OSS のコンポーネントも全てが出力形式を選べるわけではありません。 また、Datadog Agent でストリームと status の mapping を変更する方法も現時点ではなさそうです。 となるとメッセージ本文からレベルを取り出し、Status Remapper で status 属性を更新するログパイプラインを用意するのが良さそうです。 今回の自分の環境で問題になったログは、出力元のロガーで分けると klog、zap、logrus の3種類でした。 これらのロガーで、どのようにレベルを抽出すれば良いか見ていきます。 klog klog は glog の fork で、Kubernetes 本体も使用しているロガーです。 kubernetes/klog 今回の環境では、GKE のシステムコンポーネント (cni-writer、gke-metadata-server、proxy-agent etc.) や cert-manager などが klog かつ stderr でログを吐いていました。 klog の構造は以下のようになっており、先頭の L が severity を指しています。 Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg github.com/kubernetes/klog/blob/ae3961e316a310e71… severity は I が INFO、W が WARNING、E が ERROR、F が FATAL を指します。 github.com/kubernetes/klog/blob/ae3961e316a310e71… 例えば proxy-agent の次のログは INFO ですが、stderr に書かれているため Datadog 上では ERROR になっていました。 そこで、まずは Grok Parser で属性をパースしてあげます。 klog %{regex("[IWEF]"):klog.severity}%{regex("\d{4} \d{2}:\d{2}:\d{2}\.\d+")}\s+%{integer:klog.thread_id}\s+%{regex("[^\]]+"):klog.location}]\s?%{data:klog.message} 上記ルールで IWEF の値を klog.severity に書き出しましたが、klog の場合はこの severity をそのまま Status Remapper に渡すことはできません。 I と W は期待通り info と warning になり、F は emergency になりますが、E は何にも当てはまらず、info になってしまいます。 そこで、Lookup Processor で klog.severity を調整してから level 属性に入れます。 (ついでに F も critical に調整しています) I,info W,warning E,error F,critical その後 Status Remapper を挟んであげることで、proxy-agent の INFO ログは info として表示されるようになりました。 zap zap は Uber が開発しているロガーで、Kubernetes 周りでは controller-runtime を使ったコントローラーの多くが zap を使っています。 uber-go/zap 今回の環境では、gke-metrics-agent や 別記事 で導入していた Open Cluster Management の fleetconfig-controller が zap でログを吐いていました。 zap には JSON で出力する JSON encoder と、人が読みやすいテキストで出力する console encoder があります。 github.com/uber-go/zap/blob/4892335e05f14bce8a98a… console encoder はデフォルトでは、タイムスタンプ、レベル、ロガー名、呼び出し元、メッセージ、追加フィールド (JSON) を区切り文字でつないで 1 行にします。 TIMESTAMP LEVEL LOGGER CALLER MESSAGE {FIELDS} zap の console encoder の出力は、次のルールで分解します。 zap %{regex("\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d+)?(Z|[+-]\d{2}:\d{2})"):zap.timestamp}[\t ]+%{regex("(DEBUG|INFO|WARN|ERROR|DPANIC|PANIC|FATAL|debug|info|warn|error|dpanic|panic|fatal)"):zap.level:uppercase}[\t ]+%{data:zap.message} 同じ console encoder でも、出力の細かいところはコンポーネントによって異なっているため、区切り文字はタブと半角スペース、レベルは大文字と小文字の両方に対応しています。 zap のレベルは DEBUG、INFO、WARN、ERROR、DPANIC、PANIC、FATAL とあり、今のままだと DPANIC が debug に、PANIC が info になってしまいます。 ついでに FATAL は klog に合わせて critical として扱うよう、Lookup Processor で調整してあげます。 github.com/uber-go/zap/blob/4892335e05f14bce8a98a… "DEBUG,debug", "INFO,info", "WARN,warning", "ERROR,error", "DPANIC,critical", "PANIC,critical", "FATAL,critical", なお、controller-runtime の zap のオプションをコマンドライン引数に結び付けているコントローラーであれば、--zap-encoder=json を渡して JSON encoder に切り替えられます。 JSON encoder の出力には level 属性が含まれるので、前処理で status に反映され、パイプラインは要りません。 logrus logrus もメジャーな構造化ロガーで、今回の環境では Zitadel が logrus でログを出していました。 sirupsen/logrus 出力形式は TextFormatter と JSONFormatter から選べ、TextFormatter は端末以外に出力するとき key=value を並べた logfmt 風の形式になります。 time="2026-10-13T05:58:18Z" level=INFO msg="structured logger configured" caller="..." error="..." レベルは level= の後ろに info、warning、error のような語で書かれます。 スクリーンショットのログは level=INFO ですが、Datadog 上では ERROR になっていました。 logrus の TextFormatter の出力は、次の 2 つのルールで分解します。 logfmt_with_time time=%{notSpace:logfmt.time}\s+level=%{word:logfmt.level:lowercase}\s+%{data:logfmt.message} logfmt level=%{word:logfmt.level:lowercase}\s+%{data:logfmt.message} TextFormatter は設定によってタイムスタンプを出さないことがあるため、time= で始まる行と level= で始まる行の両方に対応しています。 今回のログのように時刻を time="..." と引用符で囲む場合も、引用符ごと notSpace で logfmt.time に取り込まれるので問題ありません。 logrus のレベルは以下の通りなので、zap 同様に Lookup Processor で調整してあげましょう。 github.com/sirupsen/logrus/blob/6ef0748d1177dadae… "trace,debug", "debug,debug", "info,info", "warning,warning", "error,error", "fatal,critical", "panic,critical", これでログレベルが正しく表現されるようになりました。 ! この記事の本筋とズレるので本文では言及しませんでしたが、ZITADEL はオプションでログフォーマットを JSON 化できます。4 まとめ パイプラインを適用したあとは、status:error のログがほとんどなくなりました。 これで万事解決…とは思いつつ、klog、zap、logrus とは異なる出力形式を持つロガーを採用しているコンポーネントが出てきたらその都度対応しないといけない…？ 🤔 GKE とか各 KaaS のシステムコンポーネント以外は大概ログの format などをこっちで指定できるから特に問題にならないのかな〜〜とは思いつつ、こんな複雑なことをしないといけないのはちょっと不思議な気がするな〜〜 5 もっと良い方法あるよって方、もし居たら教えてください〜〜 最後に AI Shiftではエンジニアの採用に力を入れています！少しでも興味を持っていただけましたら、カジュアル面談でお話しませんか？（オンライン・19時以降の面談も可能です！） 【面談フォームはこちら】 hrmos.co 脚注 属性とエイリアス設定 - Datadog Docs ↩︎ Pipelines (Preprocessing) - Datadog Docs ↩︎ Log Status Remapper - Datadog Docs ↩︎ ZITADEL Production Setup - ZITADEL Docs ↩︎ 「こんな複雑なことをしないといけないのはおかしい」というソフトウェアエンジニアの勘 - valid,invalid ↩︎