運用を意識したGo言語でのエラーハンドリング/ロギング

この記事は Go4 Advent Calendar 2019 7日目の記事です。

2016年にGoのAdvent Calendarを書いた時はGo3までだったのに、今年はGo7まであり、Go言語の盛り上がりを感じます。

以前書いたGo言語のエラーハンドリングの記事がじわじわと反響をいただいており、とても嬉しく思います。

上の記事を書いた当時は趣味でGo言語を嗜んでいた程度ですが、ここ1年は仕事でGoの開発に関わり、エラーハンドリングとロギングの重要性を思い知らされた次第です。自分では適切なエラーハンドリングやロギングをしたつもりでも、いざリリースしてみるとログが不足していて調査に手間取ったり、逆に過剰で精査に時間がかかったり…

本記事はここ1年Goで書いたプログラムを運用してみて得た知見を記事に起こしたものです。

TL;DR

• エラーはWrapしつつ適切なメッセージを付与して返すといいよ！
• カスタムエラー型を作って活用しよう！
• ログは極力まとめて出した方がいいよ！

本文の前に

• Go1.13から外部パッケージで行なっていたエラー処理が標準パッケージで出来るようになっていますが、本記事ではpkg/errorsを使います。

  • ちょうど今年のアドベントカレンダーにGo 1.13時代のエラー実装者のお作法という記事を投稿された方がおられるので、新しいパッケージでの処理についてはそちらを見ていただけると・・・！

• 本記事では便宜上、標準のlogパッケージを利用していますが、ログレベルを設定できないなど本番運用で利用するには不便なのでcologなどの外部ライブラリを利用したほうがいいです。

愚直にエラーを返したり自由にログ出力すると・・・

bad.go

import (
	"errors" // 利用するのは標準のerrorsパッケージ
	"log"
	...
	"example.com/external/api" // apiは外部パッケージ
)

func main() {
	if err := unitDiscographyAll(); err != nil {
		log.Fatalln("err:", err) // エラーを出力してプログラムを終了する
	}
}

func unitDiscographyAll() error {
	// 引数を変えてunitDiscography関数を呼んでいるのでどちらでエラーが発生したか判断が難しい
	if err := unitDiscography("Sphere"); err != nil {
		return err
	}
	if err := unitDiscography("TrySail"); err != nil {
		return err
	}
	return nil
}

func unitDiscography(unitName string) error {
	members, err := api.GetMembers(unitName) // return ([]api.Member, error)
	if err != nil {
		log.Println("err", err) // エラーを五月雨に出してる
		// API(外部パッケージ)のerrorをそのまま返す。ここで発生したかログだけじゃ判断が難しい
		return err
	}
	for _, m := range members {
		disco, err := api.GetDiscographies(m.ID) // return ([]api.Discography, error)
		if err != nil {			
			log.Println("err:", err) // エラーを五月雨に出してる
			// API(外部パッケージ)のerrorをそのまま返す。ここで発生したかログだけじゃ判断が難しい
			// どのmemberのデータでエラーが発生したか判断が難しい
			return err
		}
		if err := hogehoge(&m, disco); err != nil {
			log.Println("err:", err, "member:", m, "disco:", disco) // エラーを五月雨に出してる
			return err
		}
	}
	return nil
}

// なんか色々する関数
func hogehoge(m *api.Member, d []api.Discography) error {
	if ... {
		return errors.New("なんかエラーが発生したぞ")
	}
	...
	return nil
}

ちょっと色々詰め込みすぎて極端な例ですが、このコードではエラーハンドリングしたエラーをそのまま返却し、五月雨にログ出力をしています。

しかし、以下のような問題を抱えています。

• エラーがどこで発生したのかわからない
  • 自分で書いたコードならエラーメッセージからどのへんで発生したか察しはつくかもしれないが、外部のパッケージの場合エラーメッセージから特定するのはしんどい
  • pkg/errorsパッケージの%+vを使えばスタックトレースログを出力することはできるが、ログの量がエグくなる
• どのようなデータでエラーが発生したのかわからない
  • 関数の引数だったり、ループの中で呼び出した関数でエラーが発生した場合、どの値でエラーが発生したのかわからない
• ログを自由に出しすぎ
  • 1行で欲しい情報を拾えるのが理想
  • 単純に多いと気が滅入る

きれいきれいしよう

上記の問題を踏まえて、

• エラーはWrapして必要な情報を付与して呼び出し元に返す
  • 発生した箇所を特定できるようにメッセージを付与
  • データが原因になりうる場合はキー情報など最低限の情報など
• カスタムエラー型を作りエラー特定に必要な情報を持たせる
• ログを出す箇所をまとめた

import (
	"github.com/pkg/errors" // 利用するのはpkg/errorsパッケージ
	"log"
	...
)

///// HogehogeErrorを定義
type HogehogeError struct {
	err           error
	member        *api.Member
	Discographies []api.Discography
}

func (e *HogehogeError) Error() string {
	return fmt.Sprintf(
		"%s: memberID = %d, disco = %#v",
		e.err.Error(),
		e.member.ID,
		e.Discographies,
	)
}

// HogehogeError生成関数（これはなくてもいいけどあると便利）
func NewHogehogeError(err error, mem *api.Member, disco []api.Discography) error {
	return &HogehogeError{err, mem, disco}
}


func main() {
	if err := unitDiscographyAll(); err != nil {
		log.Fatalln("err:", err) // ログはここで全て出す！
	}
}

func unitDiscographyAll() error {
	if err := unitDiscography("Sphere"); err != nil {
		// エラーはWrapしてメッセージを付与する
		return errors.Wrap(err, "failed to unitDiscography. unitName = Sphere")
	}
	if err := unitDiscography("TrySail"); err != nil {
		// エラーはWrapしてメッセージを付与する
		return errors.Wrap(err, "failed to unitDiscography. unitName = TrySail")
	}
	return nil
}

func unitDiscography(unitName string) error {
	members, err := api.GetMembers(unitName) // return ([]api.Member, error)
	if err != nil {
		// エラーはWrapしてメッセージを付与する
		return errors.Wrap(err, "failed to GetMembers")
	}
	for _, m := range members {
		disco, err := api.GetDiscographies(m.ID) // return ([]api.Discography, error)
		if err != nil {
			// エラーはWrapしてメッセージを付与する
			// 全ての情報を出力するとログが重くなりがちなのでキー情報程度に
			return errors.Wrapf(err, "failed to GetDiscographies. MemberID = %d", m.ID)
		}
		if err := hogehoge(&m, disco); err != nil {
			// カスタムエラーを生成し、エラーが発生した時のデータを持たせる
			return NewHogehogeError(err, &m, disco)
		}
	}
	return nil
}

// なんか色々する関数
func hogehoge(m *api.Member, d []api.Discography) error {
	if ... {
		return errors.New("なんかエラーが発生したぞ")
	}
	...
	return nil
}

エラーをWrapする

pkg/errorsパッケージのWrapとWrapfを使います。定義は以下の通りです。

func Wrap(err error, message string) error

func Wrapf(err error, format string, args ...interface{}) error

errors.Wrap(f)は第1引数に与えられたerrorを保持しつつ、新しいerrorを返す関数です。

ログは以下のように吐かれます。

[メッセージ]: [Wrapしたエラーメッセージ]

実際書いてみるとこんな感じになります。

func main() {
	if err := hoge(); err != nil {
		log.Fatal(err) // "nansuでエラーが発生しました: (*>△<)<ナーンナーンっっ"
	}
}

func hoge() error {
	if err := nansu(); err != nil {
		return errors.Wrap(err, "nansuでエラーが発生しました")
	}
	return nil
}

func nansu() error {
	return errors.New("(*>△<)<ナーンナーンっっ")
}

Wrapを繰り返していると関数の呼び出しが二層、三層にもなってしまうと、エラー1: エラー2: エラー3のように若干冗長気味になってしまうので注意が必要です。

なお、errors.WrapでWrapしたエラーはerrors.Causeで取り出すことができます。

func main() {
	if err := hoge(); err != nil {
		log.Fatal(errors.Cause(err)) // "(*>△<)<ナーンナーンっっ"
	}
}

errors.Causeは上記のような定義になっています。

func Cause(err error) error {
	type causer interface {
		Cause() error
	}

	for err != nil {
		cause, ok := err.(causer)
		if !ok {
			break
		}
		err = cause.Cause()
	}
	return err
}

func Cause() errorが実装されていないエラーまで辿ってくれるので、どんなに深い階層で発生したエラーでもWrapし続けている限り取れます。

カスタムエラーを活用しよう

標準のerrorは文字列しか保持できませんが、エラーコードなどの特別な値をもたせたい場合や、型によってエラーハンドリングの処理を変えたい場合に有用です。

カスタムエラーについては、手前味噌ですが別の記事で詳しく解説しているのでそちらをご覧ください。

→ Go言語のエラーハンドリングについて#errorインタフェースを実装した構造体を返却する

もちろんカスタムエラーもerrors.Causeで取り出せます。

errors.Causeしたあとカスタムエラー型で型キャストしてみて成功したらその型のエラーが返ってきたことになるので、下記の例だとe変数に型キャストされたHogehogeErrorのデータが入ります。

func main() {
	if err := unitDiscographyAll(); err != nil {
		if e, ok := errors.Cause(err).(*HogehogeError); ok {
			log.Println("warn:", err, e.Discography)
		} else {
			log.Fatalln("err:", err) // ログはここで全て出す！
		}
	}
}

ログを出力する階層は(なるべく)揃える

• 極力、mainに近い方でログ出力をする
  • 辿りやすくなる
• 実際は適当なアーキテクチャやフレームワークを採用して開発するでしょうから、それに即したロギングが重要
  • アーキテクチャなら特定の層のみでログ出力をするとか
  • echoではエラーハンドリング関数HTTPErrorHandlerが用意されているのでそこにまとめるとか

最後に

プログラムは作ったら終わりではなく運用というフェーズが付きまといます。

エラーが発生しないようにプログラムを書くのが一番ですが、I/Oエラーなど避けようのないエラーもあるので、適切なエラーハンドリングを行い綺麗なログを吐くプログラムを書き、運用の負荷を少しでも軽減してみんなでハッピーになりましょう！

(o・∇・o) 終わりだよ～