出力を入力へ

プログラミングに関する自分が考えた事を中心にまとめます

railsアプリでdatadog logレベルをhttpのステータスコード依存にする

datadogに転送したアクセスログのログレベルを変更したいだけだったのに かなり時間を取られたのでそのまとめ。

やりたいこと

現在、railsアプリのログをdatadogに転送して可視化しているが、 このうち、webアクセスログの内容に応じてログレベルを変更したい。

現在はrailsログのうち例外等はエラーログとして扱ってくれるが、 webアクセスログは500系エラーであってもINFOレベルになってしまう。 200系300系はOKレベル、400系はWARNレベル、500系はERRORレベルに設定したい。

解決策

当然ながらdatadog logs pipelineで設定すればよい。 基本的には公式FAQのHow to remap custom severity values to the official log status? に従えばよい。

注意が必要なのは、 category processor で http.status_code ではなく payload.status を参照すること、 nested pipelien が必要なこと。 この解決に時間が掛かり、datadogサポートを通して何度もやりとりを行う必要が出てしまった。

はまったポイント

railsログは http.status_codeを持たない

自分たちのrailsアプリでは Semantic Logger を利用してログの構造化を行っている。 少なくともこのロガーの場合、アクセスログのHTTPステータスコードが payload.statusに記載される。 このため、 datadog logs configuration では http.status_code ではなく payload.status を参照する必要があったが これを認識できておらず、存在しない http.status_codeを参照しようとして失敗していた。

なぜ http.status_code を参照しようとしていたかというと、 datadogでは standard attribute という機能があり、 すべてのアクセスログは透過的に http.status_codeで参照できるような仕組みがあるからである。 この機能を利用していたため、無意識に http.status_codeにHTTPステータスコードがあるものだと思い込んでいた。 実際、以下のような設定が有効になっており、 http.status_code を参照すればよい状況だった。

f:id:thaim:20210403200742p:plain

standard attribute機能は pipeline を通過したログに対して payload.status の値を http.status_codeにコピーする。 ログ分析画面やconfigurationのpipeline preview画面では pipeline通過後のログを参照するため http.status_code が参照できるが pipelineの設定ではまだ属性がコピーされていないので参照できない、という仕組みだった。 結果として、以下のように payload.status を参照して処理するように設定すればよい。

f:id:thaim:20210403201035p:plain f:id:thaim:20210403201107p:plain

http status codeを持たないログが含まれている

Webのアクセスログ(rack log)は http status codeを持つが、 自分で埋め込んだログなどはhttp status codeを持たない。 このため、すべてのログが http status codeを持つという仮定は誤りである。

解決策としては、 nested pipeline によりhttp status codeを持つログを絞り込む必要がある。 これにより、status codeを持つログのみ処理対象とし、status codeを持たないログはログレベルを他の方法で決定することができる。 自分の場合は基本的に level という属性にログレベルを格納しており、datadogもデフォルトで level属性を参照してくれるので上手く動作する。 nested pipelineを用いたログのフィルタイングは以下の通り。

f:id:thaim:20210403195503p:plain

始めはstatus codeを持たないログが処理できずエラーになることを認識しておらず nested pipelineを作らなかった。 このため、pipelineが処理できる場合と処理できない場合が混在していた。 datadog ではpipelineが正常にログを処理できたか、エラーが発生したかを知る術はないため、これに気付くことができない。 このあたりdatadogにどうにかして欲しいところ。