質問内容
print
関数を使用して標準出力に書き出されたログが、ECSタスクが実行終了されるまで書き込まれない(ログストリームが作成されない)原因は何だと考えられますか?- 後述の検証にて、
logging.StreamHandler
を使用したログ書き出しではログが即時書き込まれることを確認しています。
- 後述の検証にて、
アプリケーションと基盤設定の概要
Amazon ECS + Fargateの構成で、Pythonのアプリケーションを実行しています。
ECSタスクのログドライバーにawslogs
を設定しており、CloudWatchLogsにログを書き込むように設定しています。
コンテナ内で実行されるPythonコードは、print
関数を使用して、ログ出力を行っています。
発生した事象
ECSタスクを実行すると、出力先のロググループにログストリームが作成されません。
ECSタスクの実行が完了されたタイミングで、ログストリームが作成され、ログが保存されました。
仮説
print
関数を使用してログを書き出しているアプリケーションの他に、logging
モジュールのロガーを使用してログを書き出しているアプリケーションも存在しており、こちらについては即時ログストリームが作成され、ログが保管されます。
ロガーには、logging.StreamHandler
インスタンスを渡しています。
import time
from logging import INFO, Formatter, StreamHandler, getLogger
logger = getLogger()
logger.setLevel(INFO)
if not logger.hasHandlers():
handler = StreamHandler()
logger.addHandler(handler)
formatter = Formatter(
'[%(levelname)s]\t%(asctime)s\t%(message)s\n',
'%Y-%m-%d %H:%M:%S'
)
for handler in logger.handlers:
handler.setFormatter(formatter)
logger.info('開始')
print
関数とlogging.StreamHandler
で書き込む際の動きが違う可能性があると思っています。
検証したこと
以下の2つの Pythonコードを、ECS+Fargateの構成にデプロイし、タスクを実行してみました。
なお、両タスクで使用しているDockerfileは共通のものです。
FROM python:3.9
COPY main.py main.py
CMD ["python", "main.py"]
1.print
関数を使用したログ書き出し
import time
from datetime import datetime
def log(log: str):
print(f'{datetime.now():%Y-%m-%d %H:%M:%S} {log}')
log('開始')
for _ in range(20):
time.sleep(10)
log('tick')
log('終了')
2.logging.StreamHandler
を使用したログ書き出し
import time
from logging import INFO, Formatter, StreamHandler, getLogger
logger = getLogger()
logger.setLevel(INFO)
if not logger.hasHandlers():
handler = StreamHandler()
logger.addHandler(handler)
formatter = Formatter(
'[%(levelname)s]\t%(asctime)s\t%(message)s\n',
'%Y-%m-%d %H:%M:%S'
)
for handler in logger.handlers:
handler.setFormatter(formatter)
logger.info('開始')
for _ in range(20):
time.sleep(10)
logger.info('tick')
logger.info('終了')
検証結果
1.print
関数を使用したログ書き出し
ECSタスクの実行が完了したらログストリームが作成され、ログが保管される
2.logging.StreamHandler
を使用したログ書き出し
ECSタスクの実行中にログストリームが作成され、ログが保管される
環境情報
- python: 3.9
- Fargate プラットフォームバージョン: 1.4.0
- ECSタスクオペレーティングシステム/アーキテクチャ: LINUX/-
2024/01/18 追記
追加で2点検証しました。
結論:両方とも、ECSタスクの実行中にログストリームが作成され、ログが保管される
1.1 print
関数の引数に、flush=True
を追加
print('hello', flush=True)
1.2 print
関数の引数に、file=sys.stderr
を追加
print("hello", file=sys.stderr)
@oriri san
@jackson san
コメントいただきありがとうございます。
結論
検証結果から、以下の結論を得た。
print
関数のデフォルトの動作は、sys.stdout
に出力されるようになっているが、標準出力はバッファリングを有しているため、バッファが開放されたタイミングでCloudWatchLogsに転送される。- 一方、
sys.stderr
は、バッファリングされないため、CloudWatchLogsに即時転送される。 logging.StreamHandler
のデフォルトの出力先はsys.stdeerr
のため、CloudWatchLogsに即時転送される。
print('hello', flush=True)
のようにオプション付けるとどうなりますか?StreamHandler
のデフォルトの出力先はstdout
ではなくstderr
のようですが、print("hoge", file=sys.stderr)
のようにするとどうなるでしょうか?