本記事では、Infrastructure Agent から送信されるログメッセージの文字列を解析し、New Relic 上で表示されるログのタイムスタンプとして適用する方法を解説します。
New Relic のログ管理機能では、アプリケーションやサーバーのログを任意の方法で収集して、UI 上でのデータの可視化のほか、トラブルシューティングやアラート設定に活用することができます。 New Relic へログを送信する方法には様々なオプションがありますが、中でもInfrastructure Agentにビルトインされたログファイルの転送機能は、重要なログを収集するための最もシンプルなソリューションの一つです。
ログのタイムスタンプについて
New Relic では、ログイベントをはじめとした各種テレメトリーデータにそれぞれに固有のタイムスタンプ (timestamp) 属性を保持しています。 このタイムスタンプ属性は、例えば NRQL クエリで SINCE-UNTIL 句を使用して、特定の期間内の情報を集計して可視化する場合や、アラート条件の評価を行う際にも参照されています。
Infrastructure Agent から送信されるログイベントには通常、タイムスタンプ属性は含まれていません。 そのため、New Relic が該当ログイベントを受信した時刻に基づいたタイムスタンプ属性が暗黙的に自動付与されます。
Infrastructure Agent のログ転送機能でファイルを対象とした場合、該当ファイルに新しい行が書き込まれたことをリアルタイムに検出して転送が行われます。 一般的なユースケースでは、ログに記録すべきイベントの発生から、New Relic がそのログを受信するまでのタイムラグは概ね無視できる範囲に収まることが想定されます。
一方で、ログファイルへの書き込みが非同期的またはバッファリングされていたり、通信の問題などで転送処理に大きな遅延が生じているような状況下では、以下例のようにタイムスタンプの乖離が生じる可能性があります。
タイムスタンプに乖離が生じる例
簡易的な検証環境として、Infrastructure Agent のログ転送機能を使用して、Apache デフォルトのアクセスログを New Relic に転送する環境を用意しました。 実際にこのサーバーにアクセスすると、以下のようなフォーマットでログファイルに新しい行が追記されます。
192.51.100.101 - - [24/Dec/2023:17:10:00 +0900] "GET / HTTP/1.1" 200 46
ログの時刻情報と書き込まれた時間が乖離した状況を擬似的に再現するため、現在時刻より過去のアクセスログを模した文字列をファイルに直接書き込みます。
# echo dummy - - [24/Dec/2023:09:00:00 +0900] \"GET / HTTP/1.1\" 200 46 実際にログが書き込まれた時刻は `date` です >> /var/log/httpd/access_log
このログイベントの詳細を New Relic の Logs UI 上で表示したものが以下です。
ログ本文の時刻情報は 09:00:00 を指しています。一方、New Relic 上で確認できるタイムスタンプは、ファイルに書き込まれて転送処理が行われた時刻である 17:12:51 となっており、大きな時間差が生じています。 このような状態では、時間に基づいた集計結果の正確性が損なわれてしまう可能性があります。
解決方法
New Relic が受信したログイベントに明示的なタイムスタンプ属性が含まれている場合には、受信時刻よりもそちらが優先的にタイムスタンプとして扱われます。 つまり、Infrastructure Agent がログイベントを送信する際に、あらかじめログメッセージから時刻情報を示す文字列を抽出して、New Relic に送信するペイロードのタイムスタンプ属性に追加することが有効です。
この設定を行うことにより、前述のようなタイムラグが生じてしまう状況であっても、常にログが発生した本来の時刻に基づいて集計することが可能になります。
Infrastructure Agentのログ転送とFluent Bit
Infrastructure Agent は、内部的に Fluent Bit のプラグインを使用してログの転送を行います。 ログ監視設定ディレクトリ logging.d/ に配置された yml ファイルは、Infrastructure Agent によって自動的に Fluent Bit 用の設定ファイルに変換されているため、多くのケースでは Fluent Bit の存在を意識することなく透過的に使用することができます。
今回解説する方法では、タイムスタンプに関する処理を記載した Fluent Bit の設定ファイルをあらかじめ外部に作成しておき、最終的にそれらが Infrastructure Agent によって生成される Fluent Bit 用の設定ファイルに自動的にマージされるように構成します。
Fluent Bit外部設定ファイルの作成
Fluent Bit の外部設定ファイルは、config_file と parser_file の2つに分かれています。 今回の例では、/etc/newrelic-infra/logging.d ディレクトリ内に作成していますが、これらは任意のパスで作成して構いません。
以下で紹介している設定ファイルと同じものを Gist にも転記していますので、都合の良い方法で参照してください。
config_file の [INPUT] セクションには、ログの入力ソースに関する定義を記述し、[FILTER] セクションでは、入力ソースから受け取ったデータに対して適用する処理を記述します。 今回のように Infrastructure Agent を通じて使用する場合、[SERVICE] セクションや [OUTPUT] セクションの定義は必須ではありませんが、任意に定義して上書きすることも可能です。
# fluentbit-config.conf
# 入力プラグイン tail の設定
# https://docs.fluentbit.io/manual/pipeline/inputs/tail
# Path: 対象ログファイルのフルパス
# Path_Key: ログファイルのパスを指定した属性名で付与します。ここでは New Relic の logs 属性の標準に合わせてキャメルケースを使用しています。
# Key: ログが解析されなかった場合、デフォルトの 'log' 属性を New Relic の logs 属性の標準に合わせて 'message' に変更します。
[INPUT]
Name tail
Path /var/log/httpd/access_log
Path_Key filePath
Key message
Tag httpd.access
# フィルタープラグインの設定
# https://docs.fluentbit.io/manual/pipeline/filters/parser
# Match: 付与されたタグが一致するエントリに処理を適用します。
# Parser: parsers_file 内で定義される Parser 名と一致させます。
# Key_Name: Parser に読み込ませる属性です。
# Preserve_Key: Parser で処理済みの message フィールドを削除しないようにします。
# Reserve_Data: [INPUT]で付与したタグを保持します。
[FILTER]
Name parser
Match httpd.access
Parser httpd_access_timestamp
Key_Name message
Preserve_Key On
Reserve_Data Onparsers_file では、受け取ったログを解析し、タイムスタンプを抽出する方法を記述します。 先の [FILTER] セクションで指定した処理の具体的な内容にあたります。
# fluentbit-parsers.conf
# https://docs.fluentbit.io/manual/pipeline/parsers/configuring-parser
# Regex: 正規表現を用いてマッチ条件を記述します。ここで名前付きグループとしてキャプチャされた値は New Relic 上でも属性として保持されます。
# ここでは Apache の Common Log Format を解析する例を記載しています。
# Time_Key: どのフィールドをタイムスタンプとして扱うかを指定します。
# Time_Format: Time_Key で指定したフィールドを解析するための時刻フォーマットを指定します。
[PARSER]
Name httpd_access_timestamp
Format regex
Regex ^(?<host>\S+) \S+ (?<user>\S+) \[(?<time>[^\]]+)\] "(?<method>\S+) +(?<path>.+?) (\S+)?" (?<code>\d{3})
Time_Key time
Time_Format %d/%b/%Y:%H:%M:%S %zそして、Infrastructure Agent のログ転送設定に、Fluent Bit の外部設定ファイルを使用するための設定を追加し、config_file と parser_file のフルパスをそれぞれ指定します。 この設定ファイルは /etc/newrelic-infra/logging.d ディレクトリ内に作成する必要があります。
# /etc/newrelic-infra/logging.d/fluentbit.yml
# 拡張子が.ymlであればファイル名は任意です。
# config_file および parsers_file の配置先パスは任意です。
logs:
- name: fluentbit-external-config
fluentbit:
config_file: /etc/newrelic-infra/logging.d/fluentbit-config.conf
parsers_file: /etc/newrelic-infra/logging.d/fluentbit-parsers.conf一通りの設定ファイルの配置が完了したら、Infrastructure Agent を再起動します。
なお、既存環境など、logging.d ディレクトリ内の他の yml ファイルですでに同一ログファイルの監視設定が定義されている場合には、該当箇所のコメントアウトやファイルの移動などで無効化してお試しください。
設定結果の確認
先ほどの例と同様に、現在時刻より過去のアクセスログを模した文字列をファイルに直接書き込みます。
# echo dummy - - [24/Dec/2023:09:00:00 +0900] \"GET / HTTP/1.1\" 200 46 実際にログが書き込まれた時刻は `date` です >> /var/log/httpd/access_log
このログイベントの詳細を New Relic の Logs UI 上で表示したものが以下です。
先ほどの例とは違い、New Relic 上でのログイベントのタイムスタンプは、ログが書き込まれて転送された時刻ではなく、ログメッセージに含まれる時刻情報 09:00:00 となっており、ここまでの設定が有効に動作していることがお分かり頂けるかと思います。
注意事項
- New Relic Logs API の仕様上、受信時刻より48時間以上古いタイムスタンプを持つイベントデータは破棄される制約があります。 そのため、本記事で紹介した方法は、New Relic 上で表示されるタイムスタンプと、ログメッセージ内の時刻情報との差が48時間より大きくなりうるケースには適していません。
- 今回解説した設定を適用するには、2023年1月にリリースされた newrelic-fluent-bit-output プラグインのバージョン 1.14.2 以降が必要です。 Infrastructure Agent のバージョン 1.37.0 以降には、対応済のプラグインが同梱されています。 古いバージョンを使用している場合、最新バージョンへのアップデートを検討してください。
-
今回は大まかな設定内容の紹介に留めましたが、Fluent Bit の外部設定ファイルを組み込む方法の詳細や、その他のログ転送オプションについては、ドキュメントも併せて参照してください。
本ブログに掲載されている見解は著者に所属するものであり、必ずしも New Relic 株式会社の公式見解であるわけではありません。また、本ブログには、外部サイトにアクセスするリンクが含まれる場合があります。それらリンク先の内容について、New Relic がいかなる保証も提供することはありません。
