🐙

【Go】エラーハンドリング&ログ出力にまとめて向き合う

2021/10/18に公開

echo

zap

tech

はじめに

Goのエラーハンドリング、みなさんはどうされていますか？
ちゃんと考えようとするとなかなか難しいですよね。。

小規模なプロジェクトであれば標準のerrorsパッケージや、根強い人気を誇るpkg/errorsで事足りると思います。
ただ、中規模以上になってくると痒い所に手が届かなくなってくる経験は、Goの実務経験者なら一度はあるのではないでしょうか。
ましてやログ出力も絡んでくると尚更かと思います。

エラーハンドリングのみ、ログ出力のみにフォーカスしている記事は多いですが、両方についてまとめて考えている記事はあまりないイメージです。
そこで、この記事では「中規模以上のプロジェクトにおける、エラーハンドリングとログ出力の実用的な方法」を探っていきたいと思います！

記事中に出てくるコードは以下のrepositoryにまとめてあります。
良いと思ってもらえたらスターもらえると嬉しいです。。！

前提

ある程度モノリシックなアプリであることが前提となっています。
マイクロサービスの場合、標準パッケージで足らせることができるのかと思っています。
（もちろん一概には言えませんが）

ライブラリはzapとechoを用います。
ログ出力ならzap、薄いフレームワークならecho、という風潮あると思います。（個人の主観）
echoにはある程度依存していますが、zapにはそこまで依存していないので、他パッケージのユーザの方でも適宜読み替えていけるかと思います。

ログ出力に関しては、エラーに付随するログ出力にフォーカスします。
デバッグなどのログは適宜出力すれば良いと思います。（適当）

エラーハンドリングに必要な要件

エラーハンドリングを考えるにあたり、そもそも何が必要かを明確にしておきます。

必須

呼び出し元に正常に処理が継続できなかったことを知らせることができる
エラーが発生した箇所を特定できる
呼び出し元でエラーを区別できる

オプション

下2つはログ出力よりかもしれません。

スタックトレースを出力できる
エラー発出時にエラーメッセージを付与できる
下位から上位に戻すに連れて、エラーメッセージを追加できる
- 特にクリーンアーキテクチャ・レイヤードアーキテクチャなど

ログ出力に必要な条件

ログ出力も同様にまとめておきます。

エラー発生時の状況を開発者・運用者に伝えることができ、エラー解析の助けとなる
ログの出力箇所をまとめることができる
- なるべく特定の層、箇所でログを出力する

必須要件を満たすだけなら...

エラーハンドリング単体で、上記必須要件のみを満たすだけであれば、以下の記事はとても参考になります。

結論

簡潔にまとめると以下の通りです。

カスタムエラーを用いて、エラーの区別とメッセージの格納をできるようにする
echoのCustom HTTP Error Handlerを用いて、ログ出力を一箇所にまとめる

エラーハンドリングの実装

上記の要件を踏まえ、ここからは実装を考えていきます。

カスタムエラーの活用

エラーの取り扱いに関して、以下のようなカスタムエラーを活用します。

my_error.go

package myerror

type MyError struct {
  Code       string
  Msg        string
  StackTrace string
}

// Error error interfaceを実装
func (me *MyError) Error() string {
  return fmt.Sprintf("my error: code[%s], message[%s]", me.Code, me.Msg)
}

// New コンストラクタ
func New(code string, msg string) *MyError {
  stack := zap.Stack("").String
  return &MyError{
    Code:       code,
    Msg:        msg,
    StackTrace: stack,
  }
}

それぞれのプロパティの役割は以下の通りです。
errors.Newやfmt.Errorfでは文字列しか格納できないので、それを補うために追加でCodeとStackTraceを持たせたカスタムエラーを定義しています。

Msg
- エラーメッセージを格納
Code
- エラーコードを格納
- このエラーコードを基に呼び出し元でエラーを区別する
StackTrace
- スタックトレースを格納
- コンストラクタで初期化時にスタックトレースを格納するようにする
  - zap.Stack("").Stringで取得できる

カスタムエラーの使用例

少し長いですが、entityで発生したエラーをcontrollerで区別して、HTTPコードを変更していることを理解頂ければOKです。

func main() {
  e := echo.New()
  e.GET("/hoge", controllerFunc())
  e.Logger.Fatal(e.Start(":8080"))
}

// controllerFunc controller的な関数
func controllerFunc() echo.HandlerFunc {
  return func(c echo.Context) error {
    str, err := serviceFunc()
    if err != nil {
      httpCode := http.StatusInternalServerError
      errorCode := "000-000" // 000-000を汎用エラーコードとする
      if me, ok := err.(*MyError); ok && me.Code == "001-001" {
        httpCode = http.StatusNotFound
        errorCode = "001-001"
      }
      // print "001-001のerrorでした: my error: code[001-001], message[open xxx/xxx: no such file or directory]"
      return c.JSON(httpCode, fmt.Sprintf("%sのerrorでした: %v", errorCode, err))
    }
    return c.JSON(http.StatusOK, str)
  }
}

// serviceFunc service, usecase的な関数
// あくまで例なのでentityFunc呼ぶだけ
func serviceFunc() (string, error) {
  err := entityFunc()
  if err != nil {
    return "", err
  }
  return "success!", nil
}

// entityFunc 異なる種類のエラーを返すような関数
func entityFunc() error {
  // 例えばos.Openを呼ぶ
  file := "xxx/xxx"
  _, err := os.Open(file)
  if err != nil {
    return myerror.New("001-001", err.Error())
  }
  return myerror.New("001-999", "成功してるけど、例としてとにかくエラーを返す")
}

必要な要件を満たしているか

必須要件

呼び出し元に正常に処理が継続できなかったことを知らせることができる
- entityFuncで、呼び出し元にエラーを返却することによって満たしている
エラーが発生した箇所を特定できる
- MyErrorのコンストラクタでスタックトレースを格納することによって満たしている
- スタックトレース出力処理はログ出力の時に後述
呼び出し元でエラーを区別できる
- entityFuncで発生したエラーを、controllerでMyError.Codeを用いて区別することによって満たしている

オプション

スタックトレースを出力できる
- ログ出力の時に後述
エラー発出時にエラーメッセージを付与できる
- MyError.Msgに格納することによって満たしている
下位から上位に戻すに連れて、エラーメッセージを追加できる
- 上記実装では満たしていない
- 後述

おまけ

エラー判別を関数化

me, ok := err.(*MyError); ok && me.Code == code

の処理は良く使うことになると思うので、以下のように関数定義しておくと便利です。

// isSpecificMyError ${err}がMyError、かつ${code}をもつ
func isSpecificMyError(err error, code int) bool {
  me, ok := err.(*MyError)
  return ok && me.Code == code
}

controllerで複数のエラーを区別する

上記例では001-001の場合は404、001-999の場合は500となります。
複数のエラーコードで条件分岐させたい時は、switch文を活用すると良いです。
例えば001-999の場合は422にしたい時は以下のようになります。

if me, ok := err.(*myerror.MyError); ok {
  httpCode := http.StatusInternalServerError
  switch errorCodee {
    case "001-001":
      httpCode = http.StatusNotFound
    case "001-999":
      httpCode = http.StatusUnprocessableEntity
  }
}

実際には、エラーの時点でHTTPコードは500になる可能性が高く、上記のように404にしたり422にしたりするケースはあまりないと思います。
しかし、HTTPコード以外でも分岐処理をさせたい場合があると思うので、そのような時に活用すると良さそうです。

呼び出し元でエラーメッセージを追加

エラーハンドリングのオプション要件に記載した「下位から上位に戻すに連れて、エラーメッセージを追加できる」を満たす手段について説明します。
たまーに使うくらいだと思うので、ここは参考程度でOKだと思います。

こんな感じのメソッドをMyErrorに生やしておくと良さそうです。
エラーハンドリング単体だとあまり意味をなさなそうですが、後述のログ出力と合わせるとユースケースがある。。かも。

func (me *MyError) WrapMessage(msg string) {
	me.Msg = fmt.Sprintf("%s %s", msg, me.Msg)
}

// controllerFunc controller的な関数
func controllerFunc() echo.HandlerFunc {
  return func(c echo.Context) error {
    str, err := serviceFunc()
    if err != nil {
      httpCode := http.StatusInternalServerError
      errorCode := "000-000" // 000-000を汎用エラーコードとする
      if me, ok := err.(*MyError); ok && me.Code == "001-999" {
        httpCode = http.StatusNotFound
        errorCode = "001-999"
        me.WrapMessage("001-999でしたねえ")
      }
      return c.JSON(httpCode, fmt.Sprintf("%sのerrorでした: %v", errorCode, err))
    }
    return c.JSON(http.StatusOK, str)
  }
}

fmt.Sprintf("%sのerrorでした: %v", errorCode, err))
-> "001-999のerrorでした: 001-999でしたねえ 成功してるけど、例としてとにかくエラーを返す"

このあたり、MyErrorのプロパティにerror型の変数を持たせて、エラーごとwrapできるようにした方が良かったかもと思わなくもないです。

type MyError struct {
  Code       int
  Msg        string
  StackTrace string
  err        error
}

err := doSomething()
if err != nil {
  return myerror.New("001-001", "doSomethingでエラー発生", err)
}

func doSomething() error {
  return myerror.New("001-001", "処理が継続できませんでした", nil)
}

とかやってError()をうまいこと実装して、doSomethingでエラー発生: 処理が継続できませんでしたみたいに出力させるとか？

ログ出力の実装

上記に加えて、さらにログ出力を実装します。

Custom HTTP Error Handlerの活用

echoのCustom HTTP Error Handlerを使います。

ざっくり言うと、middlewareかhandler内でerrorをreturnすると、以下のようにe.HTTPErrorHandlerに設定しておいた関数が呼び出されます。

e := echo.New()
e.HTTPErrorHandler = CustomHTTPErrorHandler

func CustomHTTPErrorHandler(err error, c echo.Context) {}

なのでこのCustomHTTPErrorHandler内にエラーハンドリング処理をまとめて書いておけます。
ログ出力やAPIのエラー時のレスポンス生成などをここにまとめておくと便利です！

Custom HTTP Error Handlerの実装例

func CustomHTTPErrorHandler(err error, c echo.Context) {
  he, ok := err.(*echo.HTTPError)
  if !ok {
    // echo.NewHTTPErrorを使っていないとここに入る
    // e.g. panicなど
    zap.S().Errorf("Unknown error: %v", err)
    c.JSON(http.StatusInternalServerError, "panicとかでした")
    return
  }

  httpCode := he.Code
  switch err := he.Message.(type) {
  case error:
    // controllerでerror型をreturnするとここに入る
    switch {
    case httpCode >= 500:
      zap.S().Errorf("Server error: %v", err)
      if me, ok := err.(*myerror.MyError); ok {
        fmt.Print(me.StackTrace)
      }
    case httpCode >= 400:
      zap.S().Infof("Client error: %v", err)
    }
    c.JSON(httpCode, "handlingされたerrorでした")
  case string:
    // echoでエラーはが発生するとここに入る
    // e.g. 存在しないURLにアクセス
    zap.S().Errorf("Echo HTTP error: %v", he)
    c.JSON(http.StatusInternalServerError, "echoのerrorでした")
  default:
    // 通常到達しない
    zap.S().Errorf("Unknown HTTP error: %v", he)
    c.JSON(http.StatusInternalServerError, "不明なerrorです")
  }
}

出力されるログのサンプルは以下の通りです。

2021-10-20T15:19:33.022+0900    ERROR   go-error-handling/http_error_handler.go:28      Server error: my error: code[001-999], message[成功してるけど、例としてとにかくエラーを返す]
github.com/yagi-eng/go-error-handling/myerror.New
        /Users/yagi-eng/go/src/github.com/yagi-eng/go-error-handling/myerror/my_error.go:22
main.entityFunc
        /Users/yagi-eng/go/src/github.com/yagi-eng/go-error-handling/main.go:59
main.serviceFunc
        /Users/yagi-eng/go/src/github.com/yagi-eng/go-error-handling/main.go:44
main.controllerFunc.func1
        /Users/yagi-eng/go/src/github.com/yagi-eng/go-error-handling/main.go:29
github.com/labstack/echo/v4.(*Echo).add.func1
        /Users/yagi-eng/go/pkg/mod/github.com/labstack/echo/v4@v4.6.1/echo.go:552
github.com/labstack/echo/v4.(*Echo).ServeHTTP
        /Users/yagi-eng/go/pkg/mod/github.com/labstack/echo/v4@v4.6.1/echo.go:662
net/http.serverHandler.ServeHTTP
        /usr/local/go/src/net/http/server.go:2878
net/http.(*conn).serve
        /usr/local/go/src/net/http/server.go:19292021-10-20T15:19:33.071+0900

基本コードに入れたコメントの通りですが、以下の3点を補足します。

スタックトレース出力

以下のように、500番台の時のみ出力するようにしています。
単なる文字列ですので、普通にfmt.Printで出力できます。

case httpCode >= 500:
  zap.S().Errorf("Server error: %v", err)
  if me, ok := err.(*myerror.MyError); ok {
    fmt.Print(me.StackTrace)
  }

zapのNewDevelopmentConfigなどを使っている場合、 DEVではWarnレベル以上、PRDではErrorレベル以上でログ出力するとスタックトレースも出力されるので、そちらはdisableにしておきます。

zapConfig := zap.NewDevelopmentConfig()
zapConfig.DisableStacktrace = true
logger, _ := zapConfig.Build()

なぜこのデフォルトのスタックトレース出力を使わないかというと、CustomHTTPErrorHandler内でzap.S().Errorとしても、controllerFunc -> serviceFunc -> entityFuncの方のスタックトレースは残らないからです。
CustomHTTPErrorHandler内の呼び出しのスタックトレースが代わりに出力されますが、特に意味のあるトレースではないです。

CustomHTTPErrorHandlerの第1引数

middlewareかhandler内でerrorをreturnすると、CustomHTTPErrorHandlerの第1引数のerr errorに入ってきます。

例えば、middlewareかhandler内でecho.NewHTTPErrorをreturnすると、CustomHTTPErrorHandlerの第1引数のerr error変数のMessageプロパティに渡ります。
日本語だとわかりづらいですが、コードだと以下のようになります。
Messageはecho.HTTPErrorのプロパティなので、errを型アサーションをして取り出します。
echo.HTTPErrorはerror interfaceを実装しています。

// middlewareかhandler内
return echo.NewHTTPError(http.StatusInternalServerError, "hoge")

func CustomHTTPErrorHandler(err error, c echo.Context) {
  // 略

  if he, ok := err.(*echo.HTTPError); ok {
    // hoge が出力される
    fmt.Print(he.Message.(string))
  }

  // 略
}

zap.S()

基本的にはこちらは気にせずに、ログ出力してるなくらいに思って頂ければOKです。

詳しく話すと少し長いので、気になる方は以下をご参考ください！

必要要件を満たしているか

エラー発生時の状況を開発者・運用者に伝えることができ、エラー解析の助けとなる
- スタックトレースを出力している
- HTTPコードによって適切なログレベルでログ出力している
- （適切なエラーメッセージかどうかは実際の実装次第）
ログの出力箇所をまとめることができる
- CustomHTTPErrorHandlerにまとめている

controllerでecho.NewHTTPErrorをreturn

前述の通り、controllerでerrorを返すことで、CustomHTTPErrorHandlerが呼び出されるようになります。
echoにはecho.NewHTTPErrorというerror型が用意されており、こちらを使うと便利です。

err != nilの時の返り値をc.JSONからecho.NewHTTPErrorにします。
また、controllerでの汎用エラーコードの定義は不要になります。
こうなると結構controllerもシンプルにまとまりますね。

// controllerFunc controller的な関数
func controllerFunc() echo.HandlerFunc {
  return func(c echo.Context) error {
    str, err := serviceFunc()
    if err != nil {
      httpCode := http.StatusInternalServerError
      if me, ok := err.(*MyError); ok && me.Code == "001-001" {
        httpCode = http.StatusNotFound
      }
      return echo.NewHTTPError(httpCode, err)
    }
    return c.JSON(http.StatusOK, str)
  }
}

おまけ

Custom HTTP Error HandlerでHTTPコードを変更する

また、エラーコードとHTTPコードが対応しているのであれば、controllerでエラーコードのチェックをせずとも、CustomHTTPErrorHandlerで一括して処理できます。

ただecho.NewHTTPErrorでセットしたHTTPコードがほぼ意味をなさなくなるのと、controllerでHTTPコードを指定すべき気がするので、一長一短ですかね。

// controllerFunc controller的な関数
func controllerFunc() echo.HandlerFunc {
  return func(c echo.Context) error {
    str, err := serviceFunc()
    if err != nil {
      return echo.NewHTTPError(http.StatusInternalServerError, err)
    }
    return c.JSON(http.StatusOK, str)
  }
}

func CustomHTTPErrorHandler(err error, c echo.Context) {
  // 略

  httpCode := he.Code
  switch err := he.Message.(type) {
  case error:
    errorCode := "000-000" // 例えば汎用的なエラーコード
    stack := ""
    if me, ok := err.(*myerror.MyError); ok {
      errorCode = me.Code
      stack = me.StackTrace
    }

    switch errorCode {
    case "001-001":
      httpCode = StatusNotFound
    case "001-999":
      httpCode = StatusUnprocessableEntity
    }

  // 略
}

◯◯を使わなかった理由

上記までがGoのエラーハンドリング・ログ出力について考えてみた結果です！
ちょっと独自な感じの実装に仕上がってますかね。

もちろんGoらしくなるべくシンプルにしたかったのですが、errors.Newなどの採用は見送りました。
ここからは採用を見送ったパッケージとその理由について書いていきます。

errors.New

こちらではエラーの区別までは満たせるのですが、エラーメッセージの付与ができないと考えました。

例えば、標準パッケージosでは、以下のようにエラーを定義しています。

var (
	ErrInvalid    = errors.New("invalid argument")
	ErrPermission = errors.New("permission denied")
	ErrExist      = errors.New("file already exists")
	ErrNotExist   = errors.New("file does not exist")
	ErrClosed     = errors.New("file already closed")
)

このように定義すれば、以下のようにエラーの区別をすることができます。
簡単なメッセージの付与もできています。

if err != nil {
    switch err {
    case os.ErrInvalid:
        fmt.Print("不正な引数")
    case os.ErrPermission:
        fmt.Print("権限なし")
    // 略
    }
}

しかし、実際はrepository関数などで以下のようなエラーメッセージを返したいこともあると思います。

func findUserByID(userID uint) {
  user, err := (userIDでユーザを検索する処理)
  if err != nil {
    return fmt.Errorf("user not found: id[%d]", userID) // userIDをメッセージに格納したい
  }
}

osパッケージのようなエラー定義だとエラーメッセージが固定になってしまい、自由にカスタマイズすることができません。
このような点からerrors.Newの採用は見送りました。

あとは単純にスタックトレースを取れないというのもお見送りの理由のひとつです。（Go2で追加されるらしい？）

fmt.Errorf

先程のrepository関数の例のように、エラーメッセージのカスタマイズはできますが、今度は逆にエラーの区別ができないので見送りました。

errors.Newとfmt.Errorfを組み合わせて、以下のようにすることもできます。
しかし、初期エラー生成でerrors.Newとfmt.Errorfの両方を使っていて少しくどいのと、err変数を格納する余地がないところにつらみを感じました。
err.Error()をfmt.Errorf内に入れ込んでもいいけど無理矢理過ぎるような。。

errNotFound := errors.New("resource not found")

func findUserByID(userID uint) {
  user, err := (userIDでユーザを検索する処理)
  if err != nil {
    return fmt.Errorf("user not found: id[%d] : %w", userID, errNotFound)
  }
}

pkg/errors

こちらを使ったとしても、上記のようなつらみが発生するのかなと思い見送りました。
errors.WithStackでスタックトレース取れるのはいいんですけどね。

補足

ざっとでも目を通しておくと、より理解が深まるかと思います。

カスタムエラー活用時の各関数の戻り値

func doSomething() error

or

func doSomething() *MyError

errorを返すと良いです。

ざっくり理解する

func fn() (int, *MyError) {
    return 42, nil
}

func main() {
    result, err := fn()
    if err != nil {
        fmt.Println("This should not be called")
    }
    fmt.Println(result, err)
}

返却するエラーの型を*MyErrorではなくerrorとすると、この問題は発生しません。

より深く理解する

It’s usually a mistake to pass back the concrete type of an error rather than error, for reasons discussed in the Go FAQ

上記で言及されているFAQでは以下の通り。

https://golang.org/doc/faq#nil_error

It's a good idea for functions that return errors always to use the error type in their signature (as we did above) rather than a concrete type such as *MyError, to help guarantee the error is created correctly. As an example, os.Open returns an error even though, if not nil, it's always of concrete type *os.PathError.

理由

上記記事より引用。
typed nil, untyped nilみたいな話ですね。

interfaces are implemented as two elements, a type T and a value V. V is a concrete value such as an int, struct or pointer, never an interface itself, and has type T. For instance, if we store the int value 3 in an interface, the resulting interface value has, schematically, (T=int, V=3)

An interface value is nil only if the V and T are both unset, (T=nil, V is not set)

func returnsError() error {
	var p *MyError = nil
	if bad() {
		p = ErrBad
	}
	return p // Will always return a non-nil error.
}

If all goes well, the function returns a nil p, so the return value is an error interface value holding (T=*MyError, V=nil). This means that if the caller compares the returned error to nil, it will always look as if there was an error even if nothing bad happened.

カスタムエラー活用時のコンストラクタの返り値

error型（interface{}型）を返すべきか、*MyError型を返すべきか、です。

type MyError struct {
	Msg  string
	Code int
}

func (err *MyError) Error() string {
	return fmt.Sprintf("err %s [code=%d]", err.Msg, err.Code)
}

// New コンストラクタ
func New(msg string, code int) *MyError {
	return &MyError{
		Msg:  msg,
		Code: code,
	}
}

*MyErrorが良いです。
error型で返すと以下のような型判定ができないためです。

if me, ok := err.(*MyError); ok {
        doSomething(me)
}

error型判定の他手段

以下のような場合はerrors.Is()が使えます.

import (
    "fmt"
    "errors"
)

ErrFoo := errors.New("foo error")

func main() {
    wrapped := fmt.Errorf("wrapped woo: %w", ErrFoo)
    if errors.Is(wrapped, ErrFoo) {
        fmt.Println("this error is caused by %v", ErrFoo)
    }
}

参考

さいごに

Goのエラーハンドリングへの自分の気持ちをぶつけてみました。笑
いかがでしたでしょうか。

結局ベストな形というのはプロジェクトによるかと思いますので、少しでも参考になれば幸いです。
また、他の方から見れば改善点とかもあるかと思いますので、もしあればご教示頂けるとうれしいです！

エラーハンドリングとログ出力が密結合になっているあたりは少し気がかりだったりします。

さいごのさいごに

Twitterの方でも、モダンな技術習得やサービス開発の様子を発信したりしているので良かったらチェックしてみてください！

また、BOT開発を通じてGoとLINE BOTにまとめて入門する記事をZennに掲載していますので、良かったらそちらもご覧ください！

はじめに

前提

エラーハンドリングに必要な要件

必須

オプション

ログ出力に必要な条件

必須要件を満たすだけなら...

結論

エラーハンドリングの実装

カスタムエラーの活用

カスタムエラーの使用例

必要な要件を満たしているか

必須要件

オプション

おまけ

エラー判別を関数化

controllerで複数のエラーを区別する

呼び出し元でエラーメッセージを追加

ログ出力の実装

Custom HTTP Error Handlerの活用

Custom HTTP Error Handlerの実装例

スタックトレース出力

CustomHTTPErrorHandlerの第1引数

zap.S()

必要要件を満たしているか

controllerでecho.NewHTTPErrorをreturn

おまけ

Custom HTTP Error HandlerでHTTPコードを変更する

◯◯を使わなかった理由

errors.New

fmt.Errorf

pkg/errors

補足

カスタムエラー活用時の各関数の戻り値

ざっくり理解する

より深く理解する

理由

カスタムエラー活用時のコンストラクタの返り値

error型判定の他手段

さいごに

さいごのさいごに

参考

Discussion