最近、仕事でAWS Lambdaを使ってます。
Python書くの楽しい。
プロジェクトのメイン言語はPHPだけど、PHPは書いててストレス溜まるからもうポイしたいｗ
ということで、Lambdaのログ周りを簡単にするためにAWS Lambda Powertoolsを導入してみました。
便利は便利だけど、timestampでハマったのでメモ。
目次
導入方法
Lambdaはある前提で。
今回はLoggerについてだけ書きます。
Lambda Consoleでモジュールを追加
AWS Lambda Powertoolsは標準モジュールに含まれていないのでLayersから追加します。
Layersをクリック。
コードタブの下にあるレイヤーに飛びます。
これはもう追加済みの状態になってますが。
レイヤーの追加をクリック。
アーキテクチャを確認します。
ドキュメントから対象のARNをコピーして、{region}を対象のものに置換してください。
東京リージョンならこう。
|
1 |
arn:aws:lambda:ap-northeast-1:017000801446:layer:AWSLambdaPowertoolsPythonV2:23 |
ARNを指定を選択してARNを入力。
検証ボタンをクリックして問題がなければ追加してください。
PythonでLoggerを用意
最小構成だとこう。
デコレータを付けるのがポイントですかね。
|
1 2 3 4 5 6 7 8 9 10 11 |
# 必要なモジュールをインポート from aws_lambda_powertools import Logger from aws_lambda_powertools.utilities.typing import LambdaContext # aws_lambda_powertoolsのLogger apt_logger = Logger() # aws_lambda_powertoolsでLoggerを使うためのデコレータ @apt_logger.inject_lambda_context def lambda_handler(event, context: LambdaContext): apt_logger.info('aws_lambda_powertoolsの時間') |
これで出力されるのがこう。
何も設定してないのにいろいろ出てますね。
timestampもちゃんと出てます。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 |
{ "level": "INFO", "location": "lambda_handler:11", "message": "aws_lambda_powertoolsの時間", "timestamp": "2023-03-10 14:16:40,804+0000", "service": "service_undefined", "cold_start": true, "function_name": "hello_world", "function_memory_size": "128", "function_arn": "arn:aws:lambda:ap-northeast-1:475391661122:function:hello_world", "function_request_id": "201922bc-47a8-4d77-9ef7-f5030e1edaea", "xray_trace_id": "1-640b3bc8-6994e8534d3603024a7b175d" } |
まぁこれ、UTCなんですけどね！！
CloudWatch側はローカルタイム＝JSTになってます。
timestampをJST(日本時間)にする
LambdaというかAWSは基本UTCなので想定内。
でもやっぱり日本時間のほうが便利なのでなんとかJSTにしたい。
環境変数にタイムゾーンを設定
ドキュメントを読むと、タイムゾーンさえ変えてしまえば何とかなりそうな感じ。
Timestamp with milliseconds, by default uses local timezone
(ミリ秒単位のタイムスタンプ。デフォルトではローカルタイムゾーンを使用します。)
ということでLambdaの環境変数に以下を追加します。
- キー：TZ
- 値：Asia/Tokyo
以前はTZはAWSの予約語だったので使っちゃダメ！と言われていましたが、現在は予約されていない環境変数に移動したので大丈夫。
これで日本時間になったのでは？！
と期待を込めて確認。
念のため標準モジュールでも出してみます。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 |
from logging import getLogger, INFO from datetime import datetime # 必要なモジュールをインポート from aws_lambda_powertools import Logger from aws_lambda_powertools.utilities.typing import LambdaContext # 時間のフォーマット用 time_str = '%Y/%m/%d %H:%M:%S.%f' # 比較用の標準モジュール logger = getLogger(__name__) logger.setLevel(INFO) # aws_lambda_powertoolsのLogger apt_logger = Logger(datefmt=time_str) # aws_lambda_powertoolsでLoggerを使うためのデコレータ @apt_logger.inject_lambda_context def lambda_handler(event, context: LambdaContext): now = datetime.now() logger.info('標準モジュールの時間：{}'.format(now.strftime(time_str))) apt_logger.info('aws_lambda_powertoolsの時間') |
結果は…
- 標準モジュール：JST
- aws_lambda_powertools：UTC
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
[INFO] 2023-03-10T14:35:26.938Z 09ad46cb-60a3-4619-963e-251d9da4238f 標準モジュールの時間：2023/03/10 23:35:26.938911 { "level": "INFO", "location": "lambda_handler:23", "message": "aws_lambda_powertoolsの時間", "timestamp": "2023/03/10 14:35:26.%f", "service": "service_undefined", "cold_start": true, "function_name": "hello_world", "function_memory_size": "128", "function_arn": "arn:aws:lambda:ap-northeast-1:475391661122:function:hello_world", "function_request_id": "09ad46cb-60a3-4619-963e-251d9da4238f", "xray_trace_id": "1-640b402e-3c9a4e05679c5c9824783fbc" } |
ローカルタイム使うって言ったじゃん。
よく見るとミリ秒も取れてないのでは？
※ミリ秒は大文字Fで取れました
タイムゾーンを確認
%Zを追加して、実際にどんな状態なのか見てみると
|
1 2 |
# 時間のフォーマット用 time_str = '%Y/%m/%d %H:%M:%S.%f %Z' |
UTCじゃなくGMTでした。
|
1 |
"timestamp": "2023/03/10 14:48:11.%f GMT" |
ドキュメント曰くutc=Trueを設定すればUTCになるとのこと。
|
1 |
logger_in_utc = Logger(service="order", utc=True) |
でもこれデフォルトがFaliseなんですよね。
UTCじゃなくGMTになってるし。
一応Trueにして実行してみましたがやっぱりだめでした。
ソースを確認
ググってもそれらしいものが見つからなかったので、ローカル環境にインストールしてソースを追いかけてみました。
対象ソースはこれ。
formatTime()を覗くと、self.use_rfc3339_iso8601の値で分岐していました。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 |
def formatTime(self, record: logging.LogRecord, datefmt: Optional[str] = None) -> str: # As of Py3.7, we can infer milliseconds directly from any datetime # saving processing time as we can shortcircuit early # Maintenance: In V3, we (and Java) should move to this format by default # since we've provided enough time for those migrating from std logging if self.use_rfc3339_iso8601: if self.utc: ts_as_datetime = datetime.fromtimestamp(record.created, tz=timezone.utc) else: ts_as_datetime = datetime.fromtimestamp(record.created).astimezone() return ts_as_datetime.isoformat(timespec="milliseconds") # 2022-10-27T17:42:26.841+0200 # converts to local/UTC TZ as struct time record_ts = self.converter(record.created) # type: ignore if datefmt is None: # pragma: no cover, it'll always be None in std logging, but mypy datefmt = self.datefmt # NOTE: Python `time.strftime` doesn't provide msec directives # so we create a custom one (%F) and replace logging record_ts # Reason 2 is that std logging doesn't support msec after TZ msecs = "%03d" % record.msecs # Datetime format codes is a superset of time format codes # therefore we only honour them if explicitly asked # by default, those migrating from std logging will use time format codes # https://docs.python.org/3/library/datetime.html#strftime-and-strptime-format-codes if self.use_datetime_directive and datefmt: # record.msecs are microseconds, divide by 1000 to get milliseconds timestamp = record.created + record.msecs / 1000 if self.utc: dt = datetime.fromtimestamp(timestamp, tz=timezone.utc) else: dt = datetime.fromtimestamp(timestamp).astimezone() custom_fmt = datefmt.replace(self.custom_ms_time_directive, msecs) return dt.strftime(custom_fmt) # Only time format codes being used elif datefmt: custom_fmt = datefmt.replace(self.custom_ms_time_directive, msecs) return time.strftime(custom_fmt, record_ts) # Use default fmt: 2021-05-03 10:20:19,650+0200 custom_fmt = self.default_time_format.replace(self.custom_ms_time_directive, msecs) return time.strftime(custom_fmt, record_ts) |
このパラメータをドキュメントで探してみると
use_rfc3339. This flag will use a format compliant with both RFC3339 and ISO8601: 2022-10-27T16:27:43.738+02:00
(use_rfc3339を使用します。このフラグは、RFC3339とISO8601の両方に準拠したフォーマットを使用します： 2022-10-27T16:27:43.738+02:00)
なるほど？
これを使うとどうにかなるかも。
use_rfc3339を指定
datefmtの代わりにuse_rfc3339を指定してみます。
|
1 |
apt_logger = Logger(use_rfc3339=True) |
これを実行すると…
無事にJSTになりました！！
よかったよかった。
無駄にWrapしてあれやこれやしてましたが、そんなの全然いらなかったですね。
コード最終形
これだけ。
めちゃくちゃシンプルです。
|
1 2 3 4 5 6 7 8 9 10 11 |
# 必要なモジュールをインポート from aws_lambda_powertools import Logger from aws_lambda_powertools.utilities.typing import LambdaContext # aws_lambda_powertoolsのLogger apt_logger = Logger(service='Loggerテスト', use_rfc3339=True) # aws_lambda_powertoolsでLoggerを使うためのデコレータ @apt_logger.inject_lambda_context def lambda_handler(event, context: LambdaContext): apt_logger.info('aws_lambda_powertoolsの時間') |
これを実行するとこう。
いい感じ。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 |
{ "level": "INFO", "location": "lambda_handler:11", "message": "aws_lambda_powertoolsの時間", "timestamp": "2023-03-11T00:21:59.386+09:00", "service": "Loggerテスト", "cold_start": true, "function_name": "hello_world", "function_memory_size": "128", "function_arn": "arn:aws:lambda:ap-northeast-1:475391661122:function:hello_world", "function_request_id": "1004e10a-4d1e-466d-83f1-84034a533f9a", "xray_trace_id": "1-640b4b17-390245a71c2969962568199d" } |
必要なら項目の追加もできるし、Lambdaのログ管理はこれでよさそうですね。
関連記事
-
-
AWS Lambda Powertoolsで外部ファイルのログを出力する
Lambdaって、lambda_function.py以外にもファイル使うことありますよね。 そんな場合でもAWS Lambda Powertoolsを使うと簡単にログを取ってくれます。 が。 ちょっ ...
続きを見る
-
-
AWS Lambda Powertools Loggerのlocationをformatする
こいつをやってて。 locationってformatできないのかなぁ。 毎回Messageにクラス名やら関数名やら書くのは面倒だぞ。。。 と思っていたらできました。 ドキュメントには（たぶん）書いてな ...
続きを見る