【小ネタ】AWS Lambdaで複数行のログを送るときの挙動を調べてみた

サーモン大好き横山です。 仕事はすでに納めてますが、最近ブログが書けておらず「これはいかん」ということで小ネタを一本ご紹介します。

ログが分割されてしまう

AWS Lambda（Python3.6）でサクッと書いた時に「JSONを確認したいな」という欲求のあまりに雑に以下のようなコードを書くことはありませんか？

import json

def lambda_handler(event, context):
v = dict(value=dict(a='abc',b='def',c=123))
v_str = json.dumps(v, ensure_ascii=False, indent=2)
print(v_str)
return 'Hello from Lambda'

はい、うちはよくあります。

でも、しばらく置いてAWS Lambdaの関数を実行したログをCloudWatch Logs側で確認するとログが1行1行分かれていて悲しみに包まれます。

サクッと実行・確認するだけならいいのですが、あとあとログからJSONから実行を追うという作業が困難になったり、JSONファイルが非常に大きくなるとこのログ出力だけでログが埋まってしまい、検索が困難になったり、JSONのテキストがまるごと欲しいのに、検索では1行分しかヒットしないという状況になります。

こういうログが残ってしまうと、運用・開発どちらでも苦労することは必至ですね。

今回はこいつの回避策をご紹介します。

loggingを使おう

多少面倒でもloggingを使い、出力しましょう。慣れればこの方法が一番嵌まらないと思います。

コード

import json
from logging import getLogger, INFO

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

def lambda_handler(event, context):
v = dict(value=dict(a='abc',b='def',c=123))
v_str = json.dumps(v, ensure_ascii=False, indent=2)
logger.info(v_str)
return 'Hello from Lambda'

CloudWatch Logs

この時、特に理由がなければ、loggerのHandlerは特に設定せずに使いましょう。 理由としては、 StreamHandler を使用して、標準出力(sys.stdout）をLogのHandlerに追加する例がサンプルコードとして多く存在しますが、これはAWS Lambdaがloggingで送るのとは別に、標準出力をCloudWatch Logsに送ってしまいます。

コード

import json
import sys
from logging import getLogger, INFO ,StreamHandler

logger = getLogger(__name__)
logger.addHandler(StreamHandler(sys.stdout))
logger.setLevel(INFO)

def lambda_handler(event, context):
v = dict(value=dict(a='abc',b='def',c=123))
v_str = json.dumps(v, ensure_ascii=False, indent=2)
logger.info(v_str)
return 'Hello from Lambda'

CloudWatch Logs

これは以下の logger.handlers を削除して実行するを行っても、default側がCloudWatch Logsに出力されるので、システム内部のAgentか何かで拾ってCloudWatch Logsに投げてるのかなーと推測します。

for h in logger.handlers:
logger.removeHandler(h)

CRを使う（筆者非推奨）

loggingを使わず、標準出力するほうの文字列からラインフィード（LF）を削除し、かわりにキャリッジリターン（以下、CR）を使用すると、CloudWatch Logsのレコードがひとまとめになります。

コード

import json

def lambda_handler(event, context):
v = dict(value=dict(a='abc',b='def',c=123))
v_str = json.dumps(v, ensure_ascii=False, indent=2)
print(v_str.replace('\n', '\r'))
return 'Hello from Lambda'

CloudWatch Logs

こっちはイレギュラーの方法なので正直おすすめしません。「出来ました」という報告だけにとどめたいと思います。 理由は、「なんでこんなコード書いてるの？」って他の人が見たら混乱するじゃないですか、主に未来の自分が。てことでプロダクションコードに入れるのはおすすめしません。

まとめ

AWS Lambdaを使って見やすい形式でCloudWatch Logsにログを残すなら、print関数を使わず、loggingを使って残しましょう。 CRは一時的な確認とかにとどめて使うようにしましょう。

それでは皆さん、良いお年を。