ぽくつなです

Cloud Functions で標準出力に書かれた JSON 文字列がそのまま jsonPayload に入るようになった

Cloud Functions Cloud Logging GCP ログ

タイトルままの話。

GCP では各プロダクトで出力したログが Cloud Logging に集約されて、横断的に見たり検索したりできて大変便利。フィルタして BigQuery に流し込めるのも最高オブ最高。仕事が楽になるっていうのはこういうことやで。

ただ、プロダクトごとにログコレクタの挙動が異なっていて微妙な気持ちになることがあるし、大抵 undocumented なんだよね。

特に、標準出力に JSON 文字列を書いた場合の挙動が

Cloud Functions の話をすると、2020/2 以前の Node10 Runtime で JSON を書いた場合は textPayload として扱われていたものが、ある日からパースされるようになっていて、構造も Google.Protobuf.WellKnownTypes.Valueになってしまったりする(こういうのを Release Note に入れないのが GCP の良くないところだと思う)。

JSON を stdout に出力することで、Cloud Logging にこう書かれていたものが

{
  "textPayload": "{\"runtime\":\"nodejs10\",\"key\":\"value\",\"array\":[1,2,3]}",
}

ある日こういう構造になる

{
  "jsonPayload": {
    "fields": {
      "array": {
        "Kind": {
          "ListValue": {
            "values": [
              {
                "Kind": {
                  "NumberValue": 1
                }
              },
              {
                "Kind": {
                  "NumberValue": 2
                }
              },
              {
                "Kind": {
                  "NumberValue": 3
                }
              }
            ]
          }
        }
      },
      "key": {
        "Kind": {
          "StringValue": "value"
        }
      },
      "runtime": {
        "Kind": {
          "StringValue": "nodejs10"
        }
      }
    }
  }
}

この構造は誰が嬉しいのか謎だけど、textPayload を期待して BigQuery に転送していた人が、この jsonPayload に変わったことで、ある日いきなり数百のカラムに直面して破滅してしまうという事件があった。かわいそう。

JSON strings logged to the console are being auto-parsed into the jsonPayload instead of the textPayload in Stackdriver Logging [147978256] - Visible to Public - Issue Tracker

もちろん、Cloud Functions から狙った構造でログを書きたい場合は Cloud Logging クライアントライブラリを使うべきで、大抵そうしているんだけど、The Twelve-Factor App XI. ログ的にも、実行環境への依存を減らす面でも、stdout に書いて済むならそうしたい。実装も簡単になる。

昨晩、前述の Issueの Status が Fixed に更新されたので、大喜びで各ランタイムで動作確認をした。
cloud-functions-playground/write-json-stdout at master · pokutuna/cloud-functions-playground

僕が確認できた範囲ではこういう感じ

runtime field
nodejs8 textPayload
nodejs10 jsonPayload
nodejs12 jsonPayload
go111 jsonPayload
go113 jsonPayload
python37 textPayload
python38 jsonPayload
java11 jsonPayload

Google.Protobuf.WellKnownTypes.Value のような構造に変換されることもなくなり、元の JSON の構造のまま jsonPayload として保存されるようになっていた。deprecated な nodejs8 がそのままなのは分かるけど、python37 はなんでだろうね。

ともあれこれで大抵のランタイムで Cloud Functions においても構造化ログをクライアントライブラリなしで書けるようになった。 たぶん特殊フィールドも動いて { "logging.googleapis.com/trace": ... } 等のフィールドを標準出力に書けば trace として拾われると思うし、ちょっとしたログの検索もしやすくなる。

まあちゃんとしたい場合は依然クライアントライブラリを使うべきなので、サボりたい時に便利って感じなんですが...

できたら GCP 内での標準的な挙動を仕様化 & 共通化してくれないかなあ