はじめに
俺俺ロガーをつくりました。
参考
- AWS Lambda Logs to One JSON Line
- Lambda + Python3.7のログをJSON形式で出力してみる（行ごとに分割されない形で）
- AWS Lambda/PythonでJSON形式でログを出すベストプラクティス
コード
ぶっちゃけ参考サイトのロガー設定を良いとこドリップしただけです。改良点は以下です。
- エラーレベルや、ロガーを仕込んだ関数、位置が分かるようにしている。
-
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": {}
}