📋

今さら聞けないCloudWatch Logsへのログ出力

に公開

PKSHA Technology ソフトウェアエンジニアの矢嶋です。

AWS でアプリケーションを動かすときは一般的なログ出力先として CloudWatch Logs を使いますが、その際にプレーンテキストで出すか JSON に構造化して出すかで、後からログを分析するときの使い勝手が大きく変わります。
基礎的な話ですが、自分のふりかえりも兼ねて改めて整理してみたいと思います。

この記事では、Python で作ったアプリを ECS と Lambda で動かし、ログの出し方と見え方を整理します。

ログの出し方

ECS

ECS で最も一般的なログドライバーである awslogs ドライバーは、コンテナの stdout / stderr をそのまま CloudWatch Logs に渡します。

プレーンテキスト(logging のデフォルト)

import logging

logger = logging.getLogger(__name__)
logging.basicConfig(level=logging.INFO)

def main():
    logger.info("info log")
    logger.warning("warning log")

    try:
        raise ValueError("sample error")
    except Exception:
        logger.exception("exception log")

main()

デフォルトの logging で出すと、ローカルでの実行時と同じように1行が1ログイベントとして出力されます。また、例外発生時のスタックトレースも行ごとに別のログイベントに分割されます。

CloudWatch Logs 上でスタックトレースがバラバラになって目grepした経験がある方は多いと思います。

ECS プレーンテキスト出力
スタックトレースが行ごとに別イベントに分割されている

JSON(自前の Formatter)

JSON Formatter を用意してログを JSON 形式で出力すると、アプリ側の1回のログ出力が CloudWatch Logs の1ログイベントとして記録されます。

import json
import logging
import traceback
from datetime import datetime, timezone

class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload: dict = {
            "timestamp": datetime.now(timezone.utc).isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        if record.exc_info and record.exc_info[0] is not None:
            payload["exception"] = {
                "type": record.exc_info[0].__name__,
                "message": str(record.exc_info[1]),
                "stacktrace": "".join(
                    traceback.format_exception(*record.exc_info)
                ),
            }
        return json.dumps(payload, ensure_ascii=False)

ECS JSON 出力

ログレベルやロガー名、メッセージなどが構造化されて出力されています。また、複数行にわたるスタックトレースも1つの JSON オブジェクトとして、CloudWatch Logs の1ログイベントに収まっています。

ECS の awslogs ドライバーは構造化を一切しないため、アプリケーション側で1行 JSON として出力する必要があります。CDK での設定は以下のようになります。

// CDK での ECS タスク定義(抜粋)
logging: new ecs.AwsLogDriver({
  logGroup,
  streamPrefix: "ecs",
}),
別解:awslogs-multiline-pattern

JSON 形式で出力する以外の方法として、awslogs-multiline-pattern を設定すると正規表現にマッチする行を新しいイベントの開始とみなし、後続の行を結合できます。スタックトレースの結合には有効ですが、パターンにマッチしない出力が意図せず直前のイベントに結合される副作用や、バッファリングによるログ配信の遅延があります。

logging: new ecs.AwsLogDriver({
  logGroup: ecsMultilineLogGroup,
  streamPrefix: "ecs",
  multilinePattern: "^(INFO|WARNING|ERROR|DEBUG|CRITICAL):.*",
}),

Lambda

プレーンテキスト(logging のデフォルト)

import logging

logger = logging.getLogger()
logger.setLevel(logging.INFO)

def lambda_handler(event, context):
    logger.info("info log")
    logger.warning("warning log")

    try:
        raise ValueError("sample error")
    except Exception:
        logger.exception("exception log")

    return {"ok": True}

Lambda プレーンテキスト出力

Lambda のプレーンテキスト設定でログを出力すると、上の画像のようになります。
分かりづらいですが、アプリ側の1出力が CloudWatch Logs の1ログイベントとして出力されており、スタックトレースも1つのログイベントにまとまっています。
ECS と違い、Lambda ランタイムがスタックトレース等も含めて1つのログイベントにまとめてくれるため、意図せずログがバラバラになる問題は起きません。
ただし、JSON として構造化されているわけではありません。

JSON(Lambda JSON ログ設定)

Lambda の場合、アプリではなく Lambda 側の設定としてログフォーマットを JSON に指定できます。この場合、アプリ側は同じコードのままでも出力が JSON 形式に構造化されます。CDK では loggingFormat: lambda.LoggingFormat.JSON を指定するだけです。

Lambda JSON 出力

アプリ側のログ出力の実装はプレーンテキストの時と同じですが、ECS で JSON Formatter を利用したときと同じように、ログは JSON 形式になっており、スタックトレースも1つの JSON オブジェクトとして収まっています。

new lambda.Function(this, "PythonJsonFn", {
  runtime: lambda.Runtime.PYTHON_3_13,
  handler: "app.lambda_handler",
  code: lambda.Code.fromAsset(path.join(PYTHON_DIR, "lambda_json")),
  loggingFormat: lambda.LoggingFormat.JSON,
  applicationLogLevelV2: lambda.ApplicationLogLevel.INFO,
  systemLogLevelV2: lambda.SystemLogLevel.INFO,
});

Lambda には高度なログ設定(Advanced logging controls)があり、ログフォーマットを JSON に切り替えるだけで標準 logging の出力が自動的に構造化されます。コード側の変更は不要です。

Lambda に最適化してよいなら AWS Lambda Powertools も選択肢になり、service, xray_trace_id の付与など便利な機能が揃っています。

Lambda と ECS で統一したい場合

Lambda の JSON ログ設定や Powertools は手軽ですが、ログの構造化が Lambda の機能に依存するため、ECS など他の環境では同じ結果になりません。アプリケーションコードを Lambda と ECS で使い回したい場合、Lambda のログ設定機能などは使わず、アプリ側で JSON 形式のログを出すことになります。

一例として、Lambda 側のログフォーマット設定をプレーンテキストにした状態で、先ほど ECS 用に作った JsonFormatter をそのまま使えば、Lambda も ECS も同じコード、同じログフォーマットになります。

# log_config.py — Lambda でも ECS でも同じコード
import json
import logging
import traceback
from datetime import datetime, timezone


class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload: dict = {
            "timestamp": datetime.now(timezone.utc).isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        if record.exc_info and record.exc_info[0] is not None:
            payload["exception"] = {
                "type": record.exc_info[0].__name__,
                "message": str(record.exc_info[1]),
                "stacktrace": "".join(
                    traceback.format_exception(*record.exc_info)
                ),
            }
        return json.dumps(payload, ensure_ascii=False)


def setup_logger(name: str = "app") -> logging.Logger:
    handler = logging.StreamHandler()
    handler.setFormatter(JsonFormatter())

    logger = logging.getLogger(name)
    logger.setLevel(logging.INFO)
    logger.handlers.clear()
    logger.addHandler(handler)
    logger.propagate = False
    return logger
# app.py
from log_config import setup_logger

logger = setup_logger("my-service")
logger.info("logger initialized")

shared Lambda 出力
Lambda(プレーンテキスト設定)での出力

shared ECS 出力
ECS での出力 — 同じフォーマット

同じコードで、Lambda も ECS も JSON 形式のログになっています。

ただし、Lambda ネイティブの JSON ログ設定には requestId が自動で付与されるという利点があります。コードを共通化して JsonFormatter に寄せると、この requestId は付与されなくなるため、必要であればアプリ側で出力する必要があります。手軽さ(Lambda のネイティブ機能)と環境間での一貫性(コードの共通化)はトレードオフになるため、用途に応じて選ぶとよいでしょう。

ログ分析時の使い勝手

プレーンテキストと JSON でのログの出し方、見え方を確認してきましたが、そもそもログを出すのは後でなにかしら調査・分析するためです。
プレーンテキストで出した場合と JSON で出した場合では分析時の使い勝手が大きく変わってきます。

プレーンテキストの場合、ログの内容はすべて1つの文字列に入っているため、分析するには文字列マッチに頼ることになります。ログレベル、エラー種別、メッセージ本文といった情報を個別に扱うことができません。

JSON の場合、各フィールドが構造化されているため、フィールドを指定した検索・フィルタ・集計が可能です。「特定の例外だけ集計する」「特定のフィールドで絞り込む」といった操作が自然に行えます。

この違いは CloudWatch Logs Insights でのクエリに限った話ではなく、S3 に書き出して Athena で分析する場合や、外部のログ分析基盤に送る場合でも同じです。構造化されたデータは、どのツールで扱っても扱いやすくなります。

CloudWatch Logs Insights を例に取ると、以下のような差が出ます。

プレーンテキストで ERROR を探す

CloudWatch Logs Insights プレーンテキストで ERROR を探す

プレーンテキストの場合、単純に文字列マッチで抽出しています。今回はサンプルで1件ヒットしているだけですが、関係ないログがヒットしてしまったり、もっと複雑な条件で検索するには限界があります。

JSON で ERROR を探す

CloudWatch Logs Insights JSON で ERROR を探す

JSON なら level でフィルタし、exception.typeexception.message を個別のカラムとして取り出せます。Insights の結果画面でも、表示する項目を自由に選べるため、大量のログから必要な情報だけを一覧できます。
今回の例にはありませんが、配列を扱ったり特定条件で集計するようなクエリも簡単に書くことができます。

まとめ

この記事では、Python の実装を例として、プレーンテキストと JSON 形式でのログ出力方法、および分析時の使い勝手の違いについて整理しました。

個人的には、基本的にログ出力は JSON 形式にしておけばよいと考えています。
また、ログの構造を設計する際は「運用時にどういうクエリで分析するか?」を考えるとよいです。ローカルで動作確認をするのであれば、jq コマンドで実際に意図したクエリが作れるかを確認するとよいでしょう。

新規にアプリを作る際、ログの設計はテーブル設計等と比べると軽視されて後回しになったりあまり考えられていないシーンもあるかと思います。しかしログ設計は後から修正しようと思っても、過去に出力されたログは直せません。アプリの設計時に、運用を楽にするためにもきちんと設計しておくとよいでしょう。

この記事がその一助になれば幸いです。

PKSHAテックブログ

Discussion