ログ収集癖

## 技術

マイクロサービス, TypeScript, gRPC, Datadog, node.js, pino, ロギング, logging, DevOps

Transcript

1. ログ収集癖 
 2023/10/27 
 レバテック開発部
 瀬尾 光希

2. |　© Leverages inc. 2 • 所属 ◦ レバテック開発部／基盤システムグループ
 • 経歴 ◦ 2021年04月 - 通信事業社に新卒入社
 ◦ 2022年07月 - レバレジーズ株式会社に中途入社
 • 出身 ◦ 宮崎県宮崎市（陸の孤島育ち）
 • 趣味 ◦ ピアノ（演奏／編曲）
 ◦ ゲーム、アニメ、漫画
 • 最近のトピック ◦ 広島県福山市のふるさと納税でカクレクマノミを買いました
 ◦ こいつと一生を過ごす
 瀬尾 光希（せお こうき） 自己紹介 自分で描いた卵かけご飯 まあまあ美味そう
3. |　© Leverages inc. 3 今日は何の話？ Node.jsのマイクロサービスを運用していて 
 • どうロギングすれば運用しやすくなるか 
 • そしてどうすればそれを実現できるか 
 を考えて改善に取り組んだことについての経験談。 
 なんやそのタイトルは
4. |　© Leverages inc. 4 目次 • はじめてのDevOpsで得たロギングの勘所 
 • ロギングのベストプラクティス 
 • Node.jsでの実現
 • 実現後の世界
 • まとめ

5. |　© Leverages inc. 5 目次 • はじめてのDevOpsで得たロギングの勘所 • ロギングのベストプラクティス 
 • Node.jsでの実現
 • 実現後の世界
 • まとめ

6. |　© Leverages inc. 6 Datadog との出会い（1/2） はじめてのDevOpsで得たロギングの勘所
7. |　© Leverages inc. 7 • ただログを集めて確認できるサイトだと思ってた ◦ 見づらいなとは思っていたけどこんなもんなんやろな〜と思ってた • ログがアプリのどこで発生していて、どう処理されて表示されているのか知らなかった ◦ ログの表示形式は仕様上決まっていて変更できないものだと思ってた Datadog との出会い（2/2） はじめてのDevOpsで得たロギングの勘所 知り合って間もない頃の Datadogちゃんが見せてくれたログ一覧
8. |　© Leverages inc. 8 ログをよくみる羽目になる はじめてのDevOpsで得たロギングの勘所 さまざまな障害対応を通して Datadogで何度もログを確認する日々 …
9. |　© Leverages inc. 9 • 日々の障害対応が簡単になるような情報を 
 ロギングしたくなる
 → ログは自分を楽にするためのものと気づく 
 • ある日Datadog にログメッセージの情報を 
 認識させる作業を行った
 → Datadogでログを分析できることを知る Datadogとロギングのことを知り始める はじめてのDevOpsで得たロギングの勘所 Datadogが取得したログをパースする処理の一部 Filterでサービス毎に限定しそれぞれ処理している ログの入口 ログの流れ
10. ログ周りがベストな状態になれば障害対応でもっと楽できるんでは …？ ログってもっと分析できるんでは …？
11. |　© Leverages inc. 11 ログのことが気になって仕方なくなった はじめてのDevOpsで得たロギングの勘所 Datadogのログ分析をちゃんと活かしたい… ログが気になって仕事に手がつかなくなる瀬尾 ログをいい感じにしたい… そして…
12. |　© Leverages inc. 12 ※実話です
13. |　© Leverages inc. 13 目次 • はじめてのDevOpsで得たロギングの勘所 
 • ロギングのベストプラクティス • Node.jsでの実現
 • 実現後の世界
 • まとめ

14. |　© Leverages inc. 14 • アプリの動作を記録する 
 • 問題の発生時にトラブルシューティングをする 
 • アプリの問題を発生前に見つけて改善する 
 • システムの利用状況を統計する 
 • 監査
 • プロファイル
 • …
 ロギングの目的 ロギングのベストプラクティス 目的が明確にあるなら、それ相応の手段を考えられるじゃない！
15. |　© Leverages inc. 15 1. ライブラリを使おう！ ◦ ログに出すべき情報を自動で出してくれるようなものがあります 2. 正しいログレベルをつけよう！ ◦ 用途ごとに適切な設定をすべし（ INFO, WARN, ERROR, …次ページでちょっと説明） 3. 集中管理できる場所に集めよう！ ◦ うちにはもうDatadogがあるね 4. 構造化されたフォーマットでロギングしよう！ ◦ ログは膨大な量になるので、人間より機械が読みやすいことの方が優先 ◦ Datadogだと、JSON形式のログは自動でパースされる 5. ログメッセージと共に Context を記録しよう！ ◦ ログを読むときの目的を考えて、それ応じた関連情報を含めておきたい 6. 実行ごとに一意な識別子（ Request ID）を含めよう！ ◦ リクエストを同時に処理するとログが混在してどれがどれだかわからんなる … ロギングのベストプラクティス（受け売り ∧ 抜粋） ロギングのベストプラクティス
16. |　© Leverages inc. 16 ログレベルの目安（諸説あり？） ロギングのベストプラクティス ログレベル 説明 備考 FATAL システムの終了を伴う致命的なエラーを記録 
 Goで出すとログ出力後 
 os.Exit(1) するらしい 
 ERROR 回復可能なプログラム実行中のエラーを記録 
 対応が必要なもの 
 WARN エラーになる可能性のあるイベントを記録 
 対応不必要だが 
 キャッチしときたいもの 
 INFO 期待されるイベントを記録（開始/終了やビジネスロジック） 
 基本はこのレベル 
 DEBUG なんでも記録
 障害対応とかで確認した い細々としたもの 
 強 💥
17. |　© Leverages inc. 17 で、うちのシステムは… ロギングのベストプラクティス 1. ライブラリを使おう！ ◦ 2. 正しいログレベルをつけよう！ ◦ 3. 集中管理できる場所に集めよう！ ◦ 4. 構造化されたフォーマットでロギングしよう！ ◦ 5. ログメッセージと共に Context を記録しよう！ ◦ 6. 実行ごとに一意な識別子（ Request ID）を含めよう！ ◦ 微妙… そらこんな顔なるわ
18. |　© Leverages inc. 18 決意 ロギングのベストプラクティス 俺がやるしか……
19. |　© Leverages inc. 19 アツい修行の日々… ロギングのベストプラクティス ♪ ロッキーのテーマ もうこれで終わってもいい ───
20. |　© Leverages inc. 20 目次 • はじめてのDevOpsで得たロギングの勘所 
 • ロギングのベストプラクティス 
 • Node.jsでの実現 • 実現後の世界
 • まとめ

21. |　© Leverages inc. 21 もともと抱えていた課題 
 • 別々のリクエストに紐づくログが混在してしまう 
 • 安直に ID をバケツリレーするにも Clean Architecture が邪魔をして大変 
 どこからでも簡単に取得できるような Request ID を作れないものか… 
 
 
 　　　　　　　　　　　　─── そして２人は出会う マジで早く実現したかった Request ID Node.jsでの実現 Controller Usecase Adapter logger.info(requestId) Request ID Request ID Request ID 遠いわ！！
22. |　© Leverages inc. 22 • Node.js が提供する API（Stable） 
 • 非同期処理においてスレッドローカル変数 
 のようなものを実現　
 AsyncLocalStorage との邂逅 Node.jsでの実現 公式ドキュメントより引用 実行ごとにストレージを作り、 使いまわしたい情報を格納しておける！
23. |　© Leverages inc. 23 AsyncLocalStorage の簡単な使い方 Node.jsでの実現 run() 中で実行される非同期関数内では、 getStore() によっていつでも “hoge” を取得できる 便利〜!!
 君の好きなオブジェクトも入るよ！
24. |　© Leverages inc. 24 AsyncLocalStorage の仕組みを簡単に解説（1/2） Node.jsでの実現 Node.jsで非同期処理を実行するとき "非同期リソース" が生成され、実行はそれに紐付けられる。 
 非同期リソースは、自分の実行IDと呼び出し元の非同期リソースIDを持つ。 
 非同期処理A
 非同期リソースA ポチッ
 • Trigger ID: X • Execution ID: A • Trigger ID: 0 (Nodejs) • Execution ID: X 非同期処理A実行！ そして非同期処理B呼び出し… 非同期リソースB • Trigger ID: A • Execution ID: B 非同期処理B実行！ 非同期リソースはクラスのインスタンスのようなものかも

25. |　© Leverages inc. 25 AsyncLocalStorage の仕組みを簡単に解説（2/2） Node.jsでの実現 AsyncLocalStorage はカスタム非同期リソースを生成して、指定した値をバケツリレーしてくれる。 
 非同期処理A
 カスタムリソースA ポチッ
 • Trigger ID: X • Execution ID: A • Store: “hoge” 
 • Trigger ID: A • Execution ID: B • Store: “hoge” 非同期処理B実行！ ありがとねぇ
 AsyncLocalStorageで実行 • Trigger ID: 0 (Nodejs) • Execution ID: X • Store: “hoge”
 非同期処理A実行！ そして非同期処理B呼び出し… 裏でバケツリレーをやってくれる カスタムリソースB
26. |　© Leverages inc. 26 ロギングのライブラリ Node.jsでの実現 がおすすめ
 • JSON形式のログ出力 • hostname, pid, UTC を自動出力 • ロギング時にトリガーする関数を設定できる • オブジェクトの自動プロパティ化 
 • 軽いらしい
 • プロパティを指定して個人情報などを 
 伏せ字にすることも可能

27. |　© Leverages inc. 27 つまり… Node.jsでの実現 1. Controller で Request ID を生成
 2. Controller から AsyncLocalStorage 内で Usecase を呼び出す
 3. Usecase 内の Pino によるロギングはその度に AsyncLocalStorage から Request ID を取得する
 4. Pino にはロギング直前の Object を（適当に）渡しておく 
 • ログの構造化
 • Request ID の付与 
 • Context の付与 
 が一気に実現

28. |　© Leverages inc. 28 俺自身が best practice… になることだ Node.jsでの実現 1. ライブラリを使おう！ ◦ 2. 正しいログレベルをつけよう！ ◦ 3. 集中管理できる場所に集めよう！ ◦ 4. 構造化されたフォーマットでロギングしよう！ ◦ 5. ログメッセージと共に Context を記録しよう！ ◦ 6. 実行ごとに一意な識別子（ Request ID）を含めよう！ ◦ ログおじいさんとログおばあさん
29. AsyncLocalStorage + Pino 銀の弾丸はここにあったんやぁ…
30. |　© Leverages inc. 30 目次 • はじめてのDevOpsで得たロギングの勘所 • ロギングのベストプラクティス • Node.jsでの実現 • 実現後の世界 • まとめ
31. |　© Leverages inc. 31 構造化ロギングによる変化｜Before 実現後の世界 • ログのすべてがメッセージフィールドに存在 
 • ログメッセージを頑張ってパースしてhostname な どの情報を得ていた 
 • Datadog が発報するアラートに付加情報が少な かった
 • トラブルシューティングの際は、ログの取捨選択を 職人技で行っていた 
 • ログ分析によるメトリクスの作成が難しかった 
 • 見づらい
 ログには Msg のみ この Grok で頑張ってパースする 
 （しかもこれでは全ての要素はパースできてない） 
 パース結果 

32. |　© Leverages inc. 32 構造化ロギングによる変化｜After✌ 実現後の世界 Request ID Msg Name パースを頑張らなくても（重要） 
 ログの要素がDatadog側で全てパースされている状態 全てのログにRequest IDが含まれていて めっちゃ検索しやすい
33. |　© Leverages inc. 33 Datadog で好きなだけログ分析できる 実現後の世界 • ドメインロジックの結果集計
 • 特定の呼び出し数とエラー発生の相関調査
 • レスポンスタイム算出
 • …
 無限の可能性
34. |　© Leverages inc. 34 • ログにも目的があって、そのための設計が大事だよ！ 
 • ログにもベストプラクティスがあるよ！ 
 • Node.js の AsyncLocalStorage は便利だよ！ 
 • ロギングライブラリの Pino おすすめだよ！ 
 • Datadog のダッシュボードいじり楽しいよ！ 
 まとめ
35. ログ収集癖 おしまい

36. |　© Leverages inc. 36 参考資料 • Logging Best Practices: The 13 You Should Know • ロギングベストプラクティス • ロギングベストプラクティスの個人的所感 • マイクロサービスのロギングベストプラクティス • 今さら聞けないログの基本と設計指針 • 11 Best Practices for Logging in Node.js • Asynchronous context tracking｜Node.js v21.1.0 documentation • JavaScriptの非同期処理をじっくり理解する (4) AbortSignal, Event, Async Context • Async Hooksを使ってリクエストごとに一意な IDをログに出力する