構造化エラーをログ出力する

Go 1.13 のリリースに合わせて spiegel-im-spiegel/errs パッケージを公開したのだが，このパッケージで構成した構造化エラーをログ出力することを考える。

まぁ標準の log パッケージでエラーメッセージを出力してもいいのだが，せっかく JSON 形式で出力できるようにしたんだから，ログ出力も JSON 形式にしたいよね。

ちうわけで，今回はこれを使います。てってれー

rs/zerolog: Zero Allocation JSON Logger

まずは準備として以下の関数を考える。

import (
    "os"

    "github.com/spiegel-im-spiegel/errs"
)

func checkFileOpen(path string) error {
    file, err := os.Open(path)
    if err != nil {
        return errs.Wrap(
            err,
            errs.WithContext("path", path),
        )
    }
    defer file.Close()

    return nil
}

ファイルをオープンするだけの関数で，オープンに失敗すると error を返す。 spiegel-im-spiegel/errs パッケージの使い方は

Go 言語用エラーハンドリング・パッケージ

を参考にしてね。

この関数を使った main() 関数を書いてみよう。まずは標準出力に対して書式 %+v を指定して普通に

func main() {
    if err := checkFileOpen("not-exist.txt"); err != nil {
        fmt.Printf("%+v\n", err)
    }
}

と出力する。これの実行結果は

$ go run sample1.go | jq .
{
  "Type": "*errs.Error",
  "Err": {
    "Type": "*os.PathError",
    "Msg": "open not-exist.txt: no such file or directory",
    "Cause": {
      "Type": "syscall.Errno",
      "Msg": "no such file or directory"
    }
  },
  "Context": {
    "function": "main.checkFileOpen",
    "path": "not-exist.txt"
  }
}

てな感じになる。うむうむ。

で，ここからが本題。

fmt.Printf() の部分を rs/zerolog によるログ出力に置き換えてみよう。とりあえず logger インスタンスの生成はこんな感じかな。

logger := zerolog.New(os.Stdout).Level(zerolog.DebugLevel).With().
    Timestamp().
    Str("role", "logger-sample").
    Logger()

まずは普通に error インスタンスをログ出力してみる。

func main() {
    logger := zerolog.New(os.Stdout).Level(zerolog.DebugLevel).With().
        Timestamp().
        Str("role", "logger-sample").
        Logger()

    if err := checkFileOpen("not-exist.txt"); err != nil {
        logger.Error().Err(err).Send()
    }
}

これの実行結果は以下の通り。

$ go run sample2.go
{"level":"error","role":"logger-sample","error":"open not-exist.txt: no such file or directory","time":"2009-11-10T23:00:00Z"}

更に jq コマンドを噛ませるとこんな感じになる。

$ go run sample.go | jq .
{
  "level": "error",
  "role": "logger-sample",
  "error": "open not-exist.txt: no such file or directory",
  "time": "2009-11-10T23:00:00Z"
}

見ての通り zerolog.Event.Err() メソッドでは単純なエラーメッセージしか出力されない（当たり前だが）。通常の error ならこれで十分だが errs.Wrap() 関数でラップした error では不十分である。

そこで zerolog.Event.Interface() メソッドのほうを使ってみる。

func main() {
    logger := zerolog.New(os.Stdout).Level(zerolog.DebugLevel).With().
        Timestamp().
        Str("role", "logger-sample").
        Logger()

    if err := checkFileOpen("not-exist.txt"); err != nil {
        logger.Error().Interface("error", err).Send()
    }
}

これでログ出力は

$ go run sample3.go | jq .
{
  "level": "error",
  "role": "logger-sample",
  "error": {
    "Type": "*errs.Error",
    "Err": {
      "Type": "*os.PathError",
      "Msg": "open not-exist.txt: no such file or directory",
      "Cause": {
        "Type": "syscall.Errno",
        "Msg": "no such file or directory"
      }
    },
    "Context": {
      "function": "main.checkFileOpen",
      "path": "not-exist.txt"
    }
  },
  "time": "2009-11-10T23:00:00Z"
}

てな感じになった。よーし，うむうむ，よーし。

rs/zerolog はパフォーマンスもよく使い勝手のいいパッケージで，しかも JSON 出力できるので加工しやすいだろう。オススメである。

ブックマーク

参考図書

プログラミング言語Go: アラン・ドノバン (著), ブライアン・カーニハン (著), 柴田芳樹 (著); 丸善出版 2016-06-20 (Release 2021-07-13); Kindle版; B099928SJD (ASIN); 評価

Kindle 版出た！一部内容が古びてしまったが，この本は Go 言語の教科書と言ってもいいだろう。感想はこちら。