GKE 上にて Pythonで logger.info() を行うとCloud logging では stderr に保存され、すべてエラーになる問題への対処法

Python のアプリケーションで、Cloud logger にログを出力したいときに

1. 標準の Python logging モジュールを利用して、ログを出力する
2. Python Cloud Logging package を使用する

上記の２つの方法があります。

不必要にパッケージを増やしたくはないので、1 の標準モジュールで Cloud Logger へ出力できないか試してみました。

標準の Python logging モジュールを試す

標準の logging モジュールでログを出力したいときに

import logging

logger = logging.getLogger(__name__)

def hoge():
	logger.info('logging Start 2021')

と、logging.info() を仕込んで、Cloud logger にログを出力してみると、logger.info() で出しているはずなのに、Cloud logger 上ではすべてエラーとして扱われてしまっています。

原因を特定するために、logger のログを見てみると logger.info() がすべて stderr標準エラーストリームへ出力されてしまっています。

{
  "textPayload": "2021-02-20 21:26:51,012 - root:predict:36 - INFO:  logging Start\n",
	...
  },
  "timestamp": "2021-02-20T12:26:51.013213826Z",
  "severity": "ERROR",
  "labels": {
	...
  },
  "logName": "projects/.../logs/stderr",
  "receiveTimestamp": "2021-02-20T12:26:55.050911180Z"
}

そのため、明示的に標準出力へ出力先を変更してみました。

import logging
import sys

logger = logging.getLogger(__name__)
handler = logging.StreamHandler(sys.stdout)
logger.addHandler(handler)

def hoge():
	logger.info('logging Start 2021')

これで解決できているはずと、Cloud Logger を見てみると

なぜか、stderr への出力は残ったまま、stdoutへの出力が新たに増えました。このままでも INFO レベルでログは残せているので目的は達成できていますが、stderrへの出力が残ってしまっているせいで Cloud logger 上でエラーが発生しているようになり問題です。なので、これを避けるために２つ目の方法である Python Cloud Logging package を利用してみます。 (というかパッケージをむやみに増やしたくないのだが利用せざるを得ない。)

Python Cloud Logging package を使用する

まずPython Client for Cloud Logging のチュートリアルをすすめて行きます。

Cloud logging の Python package のQuick Start にてわかりやすく導入方法が紹介されています。ここで混乱しやすいのが、GCP のLogging Client Libraries のドキュメントではまず Service Account を作って、GOOGLE_APPLICATION_CREDENTIALS を使用して Cloud Logging の認証を行ってくださいと書かれています。

ですが、

• GCP 上での VM でパッケージを使用するなら認証は必要ない 。ただし、デフォルトの SA を使いたくない場合や、GCP 外などで動かしたい場合は SA が必要

と本元のパッケージのドキュメントでは書かれており、こちらのほうが誤解が少なくていいですね。(公式ドキュメントだと、SA 作成時に Project > Owner を指定しろと書かれているんだけど、これって権限過多なのでは無いのだろうか??)

ちなみに GCP 上の認証過程はこちらのドキュメントが詳しく書かれているので、気になった方は御覧ください。

Authenticating as a service account

上記の認証仮定をまとめると

1. GOOGLE_APPLICATION_CREDENTIALS を参照する
2. ADC (Application Default Credentials) が、コードに紐付けられている SA を使用する
3. ADC は各サービスの SA を利用する
4. 1-3 が使用できなかった場合、認証エラーが発生する

最終的に GKE 上で Cloud logging へログを出力するためには、 以下のコードで無事に INFO のログがstderr に吐き出されることなく、stdout のみにINFOとして出力されるようになります。

import logging
import sys
# NOTE: GKE ではCotainerEngineHandler が必要
from google.cloud.logging.handlers import ContainerEngineHandler

logger = logging.getLogger(__name__)
# NOTE: stream で stdout を指定する
logger.addHandler(ContainerEngineHandler(name=__name__, stream=sys.stdout))
# NOTE: ログが重複して出力されるので、propagate を切る
logger.propagate = False

logger.info('Hello Cloud Logging.')

Appendix

• https://docs.python.org/3/howto/logging.html
• https://cloud.google.com/logging/docs/setup/python
• https://www.ai-shift.co.jp/techblog/1217
• https://stackoverflow.com/questions/48078051/duplicate-log-entries-with-google-cloud-stackdriver-logging-of-python-code-on-ku
  • 同じような質問があった