Haskell
gcp
GKE
StackdriverLogging

GKEで動作させたHaskellプログラムから出力したログが見れない問題を解決した

More than 1 year has passed since last update.

GKEでログが見れないという問題が発生

Stackdriverのログ機能を有効にして、GKE上でアプリケーションを実行すれば、標準出力にログを出力するだけで、GCPのコンソール上(ウェブ画面)でそのログを見ることができます。大変便利です。
しかし今回、Haskellで作成した実行ファイルから標準出力に出力したログが、コマンド(kubectl logs)でもコンソール上(ウェブ画面)にもどこにも現れないという問題が起こりました。原因を特定して解決するのに一日かかってしまったので、共有しておきたいと思います。

原因はログがバッファに溜め込まれていたことだった

結論を言うと、ログがバッファに溜め込まれていて、出力されていなかったことが原因でした。
結局、バッファリングのモードを変更する下のコードで解決しました。

import System.IO

hSetBuffering stdout LineBuffering -- 標準出力に出力されたデータは行単位で出力されるように設定
putStrLn "message" -- 1行出力

hSetBuffering stdout LineBufferingで1行ごとにバッファに溜め込まれたデータを標準出力に出力させるように設定します。一度この設定をしておくことで、putStrLnのタイミングでコンソール上にちゃんとログが現れるようになります。
Dockerで標準出力に出力されたデータは一旦ファイルに出力されて、それをstackdriverが拾う仕組みになっているはずです。ファイルに出力しているならば、そりゃバッファに溜める仕組みになっているだろうなと思いますが、標準出力に出力しているという感覚で考えていたため、当然1行ごとにフラッシュされるだろうと思って、この原因を見逃していました。しかも、ローカル環境でdocker logsした場合にはちゃんとログが見れていましたからなおさらです。

(ちなみに、数行putStrLnした後にhSetBufferingして、その後putStrLnすると、それまでバッファに溜まっていたログが全て一気に出力されます。)

このことから、フラッシュをすれば、改行なしでもそのタイミングでログを拾ってくれるのかと思い、下のコードを試しましたがダメでした。改行は必要なのですね。ウェブ画面で見るログメッセージの末尾が改行されていて不格好だから修正したかったのですが仕方がありません。

putStr "message" -- 改行しないでおく
hFlush stdout -- バッファに溜めたデータを出力させたい。けどだめだった。

Haskellではなく、他言語でもこのようなことが発生するかもしれません。そのような場合は、バッファリングの設定を変えてみると解決するかもしれません。