Upgrade to Pro — share decks privately, control downloads, hide ads and more …

ログ収集癖

 ログ収集癖

## 技術

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

More Decks by レバレジーズTechアカウント

Other Decks in Technology

Transcript

  1. ログ収集癖

    2023/10/27

    レバテック開発部

    瀬尾 光希


    View full-size slide

  2. | © Leverages inc.
    2
    ● 所属
    ○ レバテック開発部/基盤システムグループ

    ● 経歴
    ○ 2021年04月 - 通信事業社に新卒入社

    ○ 2022年07月 - レバレジーズ株式会社に中途入社

    ● 出身
    ○ 宮崎県宮崎市(陸の孤島育ち)

    ● 趣味
    ○ ピアノ(演奏/編曲)

    ○ ゲーム、アニメ、漫画

    ● 最近のトピック
    ○ 広島県福山市のふるさと納税でカクレクマノミを買いました

    ○ こいつと一生を過ごす

    瀬尾 光希(せお こうき)
    自己紹介
    自分で描いた卵かけご飯
    まあまあ美味そう

    View full-size slide

  3. | © Leverages inc.
    3
    今日は何の話?
    Node.jsのマイクロサービスを運用していて

    ● どうロギングすれば運用しやすくなるか

    ● そしてどうすればそれを実現できるか

    を考えて改善に取り組んだことについての経験談。

    なんやそのタイトルは

    View full-size slide

  4. | © Leverages inc.
    4
    目次
    ● はじめてのDevOpsで得たロギングの勘所 

    ● ロギングのベストプラクティス 

    ● Node.jsでの実現

    ● 実現後の世界

    ● まとめ


    View full-size slide

  5. | © Leverages inc.
    5
    目次
    ● はじめてのDevOpsで得たロギングの勘所
    ● ロギングのベストプラクティス 

    ● Node.jsでの実現

    ● 実現後の世界

    ● まとめ


    View full-size slide

  6. | © Leverages inc.
    6
    Datadog との出会い(1/2)
    はじめてのDevOpsで得たロギングの勘所

    View full-size slide

  7. | © Leverages inc.
    7
    ● ただログを集めて確認できるサイトだと思ってた
    ○ 見づらいなとは思っていたけどこんなもんなんやろな〜と思ってた
    ● ログがアプリのどこで発生していて、どう処理されて表示されているのか知らなかった
    ○ ログの表示形式は仕様上決まっていて変更できないものだと思ってた
    Datadog との出会い(2/2)
    はじめてのDevOpsで得たロギングの勘所
    知り合って間もない頃の
    Datadogちゃんが見せてくれたログ一覧

    View full-size slide

  8. | © Leverages inc.
    8
    ログをよくみる羽目になる
    はじめてのDevOpsで得たロギングの勘所
    さまざまな障害対応を通して
    Datadogで何度もログを確認する日々 …

    View full-size slide

  9. | © Leverages inc.
    9
    ● 日々の障害対応が簡単になるような情報を

    ロギングしたくなる

    → ログは自分を楽にするためのものと気づく

    ● ある日Datadog にログメッセージの情報を

    認識させる作業を行った

    → Datadogでログを分析できることを知る
    Datadogとロギングのことを知り始める
    はじめてのDevOpsで得たロギングの勘所
    Datadogが取得したログをパースする処理の一部
    Filterでサービス毎に限定しそれぞれ処理している
    ログの入口
    ログの流れ

    View full-size slide

  10. ログ周りがベストな状態になれば障害対応でもっと楽できるんでは …?
    ログってもっと分析できるんでは …?

    View full-size slide

  11. | © Leverages inc.
    11
    ログのことが気になって仕方なくなった
    はじめてのDevOpsで得たロギングの勘所
    Datadogのログ分析をちゃんと活かしたい…
    ログが気になって仕事に手がつかなくなる瀬尾
    ログをいい感じにしたい…
    そして…

    View full-size slide

  12. | © Leverages inc.
    12
    ※実話です

    View full-size slide

  13. | © Leverages inc.
    13
    目次
    ● はじめてのDevOpsで得たロギングの勘所 

    ● ロギングのベストプラクティス
    ● Node.jsでの実現

    ● 実現後の世界

    ● まとめ


    View full-size slide

  14. | © Leverages inc.
    14
    ● アプリの動作を記録する 

    ● 問題の発生時にトラブルシューティングをする 

    ● アプリの問題を発生前に見つけて改善する 

    ● システムの利用状況を統計する 

    ● 監査

    ● プロファイル

    ● …

    ロギングの目的
    ロギングのベストプラクティス
    目的が明確にあるなら、それ相応の手段を考えられるじゃない!

    View full-size slide

  15. | © Leverages inc.
    15
    1. ライブラリを使おう!
    ○ ログに出すべき情報を自動で出してくれるようなものがあります
    2. 正しいログレベルをつけよう!
    ○ 用途ごとに適切な設定をすべし( INFO, WARN, ERROR, …次ページでちょっと説明)
    3. 集中管理できる場所に集めよう!
    ○ うちにはもうDatadogがあるね
    4. 構造化されたフォーマットでロギングしよう!
    ○ ログは膨大な量になるので、人間より機械が読みやすいことの方が優先
    ○ Datadogだと、JSON形式のログは自動でパースされる
    5. ログメッセージと共に Context を記録しよう!
    ○ ログを読むときの目的を考えて、それ応じた関連情報を含めておきたい
    6. 実行ごとに一意な識別子( Request ID)を含めよう!
    ○ リクエストを同時に処理するとログが混在してどれがどれだかわからんなる …
    ロギングのベストプラクティス(受け売り ∧ 抜粋)
    ロギングのベストプラクティス

    View full-size slide

  16. | © Leverages inc.
    16
    ログレベルの目安(諸説あり?)
    ロギングのベストプラクティス
    ログレベル 説明 備考
    FATAL システムの終了を伴う致命的なエラーを記録
    
 Goで出すとログ出力後 

    os.Exit(1) するらしい 

    ERROR 回復可能なプログラム実行中のエラーを記録
    
 対応が必要なもの 

    WARN エラーになる可能性のあるイベントを記録
    
 対応不必要だが 

    キャッチしときたいもの 

    INFO 期待されるイベントを記録(開始/終了やビジネスロジック)
    
 基本はこのレベル 

    DEBUG なんでも記録
 障害対応とかで確認した
    い細々としたもの 


    💥

    View full-size slide

  17. | © Leverages inc.
    17
    で、うちのシステムは…
    ロギングのベストプラクティス
    1. ライブラリを使おう!

    2. 正しいログレベルをつけよう!

    3. 集中管理できる場所に集めよう!

    4. 構造化されたフォーマットでロギングしよう!

    5. ログメッセージと共に Context を記録しよう!

    6. 実行ごとに一意な識別子( Request ID)を含めよう!

    微妙…
    そらこんな顔なるわ

    View full-size slide

  18. | © Leverages inc.
    18
    決意
    ロギングのベストプラクティス
    俺がやるしか……

    View full-size slide

  19. | © Leverages inc.
    19
    アツい修行の日々…
    ロギングのベストプラクティス
    ♪ ロッキーのテーマ
    もうこれで終わってもいい ───

    View full-size slide

  20. | © Leverages inc.
    20
    目次
    ● はじめてのDevOpsで得たロギングの勘所 

    ● ロギングのベストプラクティス 

    ● Node.jsでの実現
    ● 実現後の世界

    ● まとめ


    View full-size slide

  21. | © Leverages inc.
    21
    もともと抱えていた課題 

    ● 別々のリクエストに紐づくログが混在してしまう 

    ● 安直に ID をバケツリレーするにも Clean Architecture が邪魔をして大変 

    どこからでも簡単に取得できるような Request ID を作れないものか… 



                ─── そして2人は出会う
    マジで早く実現したかった Request ID
    Node.jsでの実現
    Controller
    Usecase
    Adapter
    logger.info(requestId)
    Request ID
    Request ID
    Request ID
    遠いわ!!

    View full-size slide

  22. | © Leverages inc.
    22
    ● Node.js が提供する API(Stable)

    ● 非同期処理においてスレッドローカル変数

    のようなものを実現 

    AsyncLocalStorage との邂逅
    Node.jsでの実現
    公式ドキュメントより引用
    実行ごとにストレージを作り、
    使いまわしたい情報を格納しておける!

    View full-size slide

  23. | © Leverages inc.
    23
    AsyncLocalStorage の簡単な使い方
    Node.jsでの実現
    run() 中で実行される非同期関数内では、
    getStore() によっていつでも “hoge” を取得できる
    便利〜!!

    君の好きなオブジェクトも入るよ!

    View full-size slide

  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実行!
    非同期リソースはクラスのインスタンスのようなものかも


    View full-size slide

  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

    View full-size slide

  26. | © Leverages inc.
    26
    ロギングのライブラリ
    Node.jsでの実現
    がおすすめ

    ● JSON形式のログ出力
    ● hostname, pid, UTC を自動出力
    ● ロギング時にトリガーする関数を設定できる
    ● オブジェクトの自動プロパティ化

    ● 軽いらしい

    ● プロパティを指定して個人情報などを

    伏せ字にすることも可能


    View full-size slide

  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 の付与 

    が一気に実現


    View full-size slide

  28. | © Leverages inc.
    28
    俺自身が best practice… になることだ
    Node.jsでの実現
    1. ライブラリを使おう!

    2. 正しいログレベルをつけよう!

    3. 集中管理できる場所に集めよう!

    4. 構造化されたフォーマットでロギングしよう!

    5. ログメッセージと共に Context を記録しよう!

    6. 実行ごとに一意な識別子( Request ID)を含めよう!

    ログおじいさんとログおばあさん

    View full-size slide

  29. AsyncLocalStorage + Pino
    銀の弾丸はここにあったんやぁ…

    View full-size slide

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

    View full-size slide

  31. | © Leverages inc.
    31
    構造化ロギングによる変化|Before
    実現後の世界
    ● ログのすべてがメッセージフィールドに存在

    ● ログメッセージを頑張ってパースしてhostname な
    どの情報を得ていた

    ● Datadog が発報するアラートに付加情報が少な
    かった

    ● トラブルシューティングの際は、ログの取捨選択を
    職人技で行っていた

    ● ログ分析によるメトリクスの作成が難しかった

    ● 見づらい

    ログには Msg のみ
    この Grok で頑張ってパースする 

    (しかもこれでは全ての要素はパースできてない) 

    パース結果 


    View full-size slide

  32. | © Leverages inc.
    32
    構造化ロギングによる変化|After✌
    実現後の世界
    Request ID Msg
    Name
    パースを頑張らなくても(重要) 

    ログの要素がDatadog側で全てパースされている状態
    全てのログにRequest IDが含まれていて
    めっちゃ検索しやすい

    View full-size slide

  33. | © Leverages inc.
    33
    Datadog で好きなだけログ分析できる
    実現後の世界
    ● ドメインロジックの結果集計

    ● 特定の呼び出し数とエラー発生の相関調査

    ● レスポンスタイム算出

    ● …

    無限の可能性

    View full-size slide

  34. | © Leverages inc.
    34
    ● ログにも目的があって、そのための設計が大事だよ! 

    ● ログにもベストプラクティスがあるよ! 

    ● Node.js の AsyncLocalStorage は便利だよ! 

    ● ロギングライブラリの Pino おすすめだよ! 

    ● Datadog のダッシュボードいじり楽しいよ! 

    まとめ

    View full-size slide

  35. ログ収集癖
    おしまい


    View full-size slide

  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をログに出力する

    View full-size slide