GKEからpythonでCloud Loggingにログを流す方法

こんにちは、AIチームの杉山です。
今回は開発寄りでAI的な内容ではないですが、python on GKEの実装上のTipsを紹介します。

はじめに

機械学習や自然言語処理を活用したアプリケーションの多くがpythonで実装されており、我々のプロダクトでもpythonを使用しています。また、機械学習モデルの推論APIをservingする環境としてkubernetesが使用される事例も多く、我々もkubernetesのGCP版であるGKE(Google Kubernetes Engine)を使用しています。GKEは非常に便利なサービスで私も気に入って使っているのですが、pythonでのloggingに癖がありハマったため、その問題点と解決策を紹介させていただきます。

やりたいこと

  • GKE上で動作するpythonアプリケーションから、Cloud Logging(旧Stackdriver Logging)へログを書き出す
  • severityを設定することで、Cloud Loggingのコンソールから見たときにseverityに応じて適切に出し分けられている(下図)
Cloud Loggingへのログがseverityに応じて適切に出し分けられている例。
左のマークがseverityに従って変わっている。

問題点

上記の要件を実現するための実装方針は大きく以下の2つになります。

  1. python標準のloggingモジュールを用いる
  2. Cloud Loggingのpythonクライアントを用いる

python標準のloggingモジュールを用いる

1に関して、まず特別なことを何も行わず以下のようなよくある実装を行いました。

import logging

logger = getLogger(__name__)
logger.info('info message.')

すると、[INFO]: info message.というメッセージはCloud Loggingに流れるものの、出力がstderrに出てしまい、severityが全てERRORに上書きされてしまいました。これではログが出るたびにエラー扱いになってしまいログへの監視の仕組みを入れることができません。
そこで、loggingのハンドラへのstreamをstdoutに変えたところ、stdoutへのログはseverityに応じて振り分けられたのですが、消したはずのstderrへのログも変わらず出力されるという挙動になってしまいました。これではログへの監視を入れるという目的を達することができないため一度諦めて2つ目の方法を試すことにしました。

Cloud Loggingのpythonクライアントを用いる

GCPのpythonクライアントは充実しており、Cloud Loggingのためのクライアントも存在します。そこで、この辺りこの辺りの公式ドキュメントのサンプル実装に従って試してみました。

import logging
import google.cloud.logging
from google.cloud.logging.handlers import CloudLoggingHandler

client = google.cloud.logging.Client()
handler = CloudLoggingHandler(client)
cloud_logger = logging.getLogger('cloudLogger')
cloud_logger.setLevel(logging.INFO)
cloud_logger.addHandler(handler)
cloud_logger.info('info message.')

しかし、この実装ではなぜかCloud Loggingへのログが出力されませんでした。なぜだろうと思って色々調べていたのですが、その過程でCloudLoggingHandlerの定義を読んでいたところ、ある記述に気がつきました。

This handler is used when not in GAE or GKE environment.

解決策

ということで、GKEではCloudLoggingHandlerが使われないため、サンプル実装に従ってそれを設定しても意味がないのでした。他のドキュメントを読んでいると、GKEの場合はContainerEngineHandlerを使う必要があることがわかりました。
そこで、loggerにContainerEngineHandlerを設定し、streamをstdoutに流すことで欲しいログが得られました。ただし、追加するだけではルートロガーに伝播してしまいログが二重に出てしまうため、そちらはオフにしておきましょう。以上を踏まえると、以下のような実装で要件を満たすことができました。

import logging
import sys
from google.cloud.logging.handlers import ContainerEngineHandler

logger = getLogger(__name__)
logger.addHandler(ContainerEngineHandler(log_name, stream=sys.stdout))
logger.propagate = False
logger.info('info message.')

終わりに

使っているのはGKEなのにGCEのHandlerを使うことになっていたため必要な情報が書かれているドキュメントにたどり着くのに時間がかかってしまいました。Cloud LoggingはStackdriver Loggingから名称が変わったばかりのサービスですが、上記のドキュメント内にはStackdriver Loggingの記述が残っていたりとこれは過渡期ゆえの問題なのかな、と思いますが、正しく情報を探すことの難しさを感じました。
ひとまずGKEからseverityに応じて適切にログを出し分けられるようになったため、次はログへの監視の仕組みを取り入れていきたいと思います。
この記事が同じことで困っている方の参考になれば幸いです。