はじめに

俺俺ロガーをつくりました。

参考

コード

ぶっちゃけ参考サイトのロガー設定を良いとこドリップしただけです。改良点は以下です。

エラーレベルや、ロガーを仕込んだ関数、位置が分かるようにしている。
logger('parameter %s', x)のような形で、第一引数にメッセージ、第二引数以降に変数という、元のloggerの入力の仕方が可能。
例外時はlogger.exception(e)とすればtracebackにスタックトレースが出力される。
日本語も出力可能。
**aws_request_idも出力できる。**デコレータを使用してLoggerAdapter経由でaws_request_idを出力するよう設定しています。

utils.py

import logging
import json
import os
import traceback


class FormatterJSON(logging.Formatter):
    def format(self, record):
        record.message = record.getMessage()
        if self.usesTime():
            record.asctime = self.formatTime(record, self.datefmt)
        j = {
            'levelname': record.levelname,
            'levelno': record.levelno,
            'time': '%(asctime)s.%(msecs)dZ' % dict(asctime=record.asctime, msecs=record.msecs),
            'aws_request_id': getattr(record, 'aws_request_id', '00000000-0000-0000-0000-000000000000'),
            'message': record.message,
            'module': record.module,
            'filename': record.filename,
            'funcName': record.funcName,
            'lineno': record.lineno,
            'traceback': {},
            'extra_data': record.__dict__.get('data', {}),
        }
        if record.exc_info:
            exception_data = traceback.format_exc().splitlines()
            j['traceback'] = exception_data

        return json.dumps(j, ensure_ascii=False)


class LoggerAdapter(logging.LoggerAdapter):
    def __init__(self, logger):
        super().__init__(logger, extra={})
        
    def inject_aws_context(self, lambda_handler):
        def wrapper(event, context):
            self.extra['aws_request_id'] = context.aws_request_id
            return lambda_handler(event, context)
        return wrapper
        
        
def get_logger():
    stream_handler = logging.StreamHandler()
    stream_handler.setFormatter(FormatterJSON(
        '[%(levelname)s]\t%(asctime)s.%(msecs)dZ\t%(levelno)s\t%(message)s\t%(aws_request_id)s\n','%Y-%m-%dT%H:%M:%S'
    ))
    logger = logging.getLogger(__name__)
    logger.addHandler(stream_handler)
    logger.setLevel(os.environ.get('LOG_LEVEL', 'INFO'))
    logger = LoggerAdapter(logger)
    return logger

正常時のログ。

lambda_function.py

import json
import os
import traceback

from utils import get_logger

logger = get_logger()

@logger.inject_aws_context
def lambda_handler(event, context):
    value = dict(a='abc', b='def', c=123)
    logger.info('Start hello Func', extra=dict(data=value))
    
    return {
        'statusCode': 200,
        'body': json.dumps('Hello from Lambda!')
    }

{
    "levelname": "INFO",
    "levelno": 20,
    "time": "2021-03-16T15:12:14.836Z",
    "aws_request_id": "9780f8b7-3d76-4e74-9b9b-d23e0a542119",
    "message": "Start hello Func",
    "module": "lambda_function",
    "filename": "lambda_function.py",
    "funcName": "lambda_handler",
    "lineno": 12,
    "traceback": {},
    "extra_data": {}
}

例外のログ。

lambda_function.py

import json
import os
import traceback

from utils import get_logger

logger = get_logger()

@logger.inject_aws_context
def lambda_handler(event, context):
    value = dict(a='abc', b='def', c=123)
    
    try:
        print(1/0)
    except ZeroDivisionError as error:
        logger.exception(error)
    
    return {
        'statusCode': 200,
        'body': json.dumps('Hello from Lambda!')
    }

{
    "levelname": "ERROR",
    "levelno": 40,
    "time": "2021-03-16T15:16:20.662Z",
    "aws_request_id": "ca30328e-ca87-470a-bbfc-896facc4e6d8",
    "message": "division by zero",
    "module": "lambda_function",
    "filename": "lambda_function.py",
    "funcName": "lambda_handler",
    "lineno": 17,
    "traceback": [
        "Traceback (most recent call last):",
        "  File \"/var/task/lambda_function.py\", line 15, in lambda_handler",
        "    print(1/0)",
        "ZeroDivisionError: division by zero"
    ],
    "extra_data": {}
}

ここだけの話

Lambda Powertools を使えばいいのでは？
https://dev.classmethod.jp/articles/lambda-powertools/

多分ダメなやつ

以下は以前考えていたものなんですが、root ロガーを汚してしまうので、他にloggingを使用しているモジュールがあると壊れる可能性があります。

logging.basicConfig()でデフォルトハンドラー（ストリームハンドラー）を設定することでロガーの設定の記述量を少なくした。Lambdaではストリームハンドラーだけあれば良いので、これで良いと判断した。

import logging
import json
import os
import traceback

class FormatterJSON(logging.Formatter):
    def format(self, record):
        record.message = record.getMessage()
        if self.usesTime():
            record.asctime = self.formatTime(record, self.datefmt)
        j = {
            'levelname': record.levelname,
            'levelno': record.levelno,
            'time': '%(asctime)s.%(msecs)dZ' % dict(asctime=record.asctime, msecs=record.msecs),
            'aws_request_id': getattr(record, 'aws_request_id', '00000000-0000-0000-0000-000000000000'),
            'message': record.message,
            'module': record.module,
            'filename': record.filename,
            'funcName': record.funcName,
            'lineno': record.lineno,
            'traceback': {},
            'extra_data': record.__dict__.get('data', {}),
        }
        if record.exc_info:
            exception_data = traceback.format_exc().splitlines()
            j['traceback'] = exception_data
        
        return json.dumps(j, ensure_ascii=False)

logging.basicConfig()
logging.getLogger().handlers[0].setFormatter(FormatterJSON(
    '[%(levelname)s]\t%(asctime)s.%(msecs)dZ\t%(levelno)s\t%(message)s\n','%Y-%m-%dT%H:%M:%S'
))
logger = logging.getLogger(__name__)
logger.setLevel(os.environ.get('LOG_LEVEL', 'INFO'))

正常ログの例。

def lambda_handler(event, context):
    value = dict(a='abc', b='def', c=123)
    logger.info('Start hello Func', extra=dict(data=value))
    
    return {
        'statusCode': 200,
        'body': json.dumps('Hello from Lambda!')
    }

{
    "levelname": "INFO",
    "levelno": 20,
    "time": "2021-02-09T05:42:58.503Z",
    "aws_request_id": "c199c00d-a2ae-4081-9fd2-7b513e7c55ba",
    "message": "Start hello Func",
    "module": "lambda_function",
    "filename": "lambda_function.py",
    "funcName": "lambda_handler",
    "lineno": 40,
    "traceback": {},
    "extra_data": {
        "a": "abc",
        "b": "def",
        "c": 123
    }
}

例外ログの例。

def lambda_handler(event, context):
    value = dict(a='abc', b='def', c=123)

    try:
        print(1/0)
    except ZeroDivisionError as error:
        logger.exception(error)
    
    return {
        'statusCode': 200,
        'body': json.dumps('Hello from Lambda!')
    }

{
    "levelname": "ERROR",
    "levelno": 40,
    "time": "2021-02-09T05:46:43.80Z",
    "aws_request_id": "e8c0ce56-7dd8-4a39-ac4f-12afbc0ebb32",
    "message": "division by zero",
    "module": "lambda_function",
    "filename": "lambda_function.py",
    "funcName": "lambda_handler",
    "lineno": 44,
    "traceback": [
        "Traceback (most recent call last):",
        "  File \"/var/task/lambda_function.py\", line 42, in lambda_handler",
        "    print(1/0)",
        "ZeroDivisionError: division by zero"
    ],
    "extra_data": {}
}