github.com/labstack/echoのロギングについての備忘録です.
echoのログを活用していきたい...と考えてます。
前提
- go 1.19
- echo v4.10.0
- echoのErrorHandlerはDefaultHTTPErrorHandlerを使用
はじめに、正常応答させてみる
echoのmiddleware.Loggerをカスタマイズせずに使用します。
// ~省略
e := echo.New()
e.Use(middleware.Logger())
// ~省略
e.GET("/", func(ctx echo.Context) error {
  return ctx.String(http.StatusOK, "Hello world!")
})
curlで呼び出します
#localhost, port=8888で実行しているとき
curl http://localhost:8888/
logの内容
{"time":"2023-01-22T03:52:21.307000008Z","id":"","remote_ip":"/*remote ip*/","host":"localhost:8888","method":"GET","uri":"/","user_agent":"curl/7.84.0","status":200,"error":"","latency":134542,"latency_human":"134.542µs","bytes_in":0,"bytes_out":12}
正常な振る舞いをしているのでerrorは空です
エラー応答について
正常時のログを確認したので、エラー応答のさせ方によるログやレスポンスの違いを見ていきます
1. echo.HTTPErrorを返してみる
e.GET("/", func(ctx echo.Context) error {
  // return ctx.String(http.StatusOK, "Hello world!")
  return &echo.HTTPError{Code: http.StatusNotFound, Message: "エラーメッセージ", Internal: errors.New("エラー内容")}
})
logの内容です
{"time":"2023-01-22T04:01:40.613879378Z","id":"","remote_ip":"/*remote ip*/","host":"localhost:8888","method":"GET","uri":"/","user_agent":"curl/7.84.0","status":404,"error":"code=404, message=エラーメッセージ, internal=エラー内容","latency":84958,"latency_human":"84.958µs","bytes_in":0,"bytes_out":39}
errorの値としてecho.HTTPErrorで定義した内容(Code, message, internal)が出力されてます。
この時のhttpレスポンスのBodyです
{"message":"エラーメッセージ"}
(補足)echo.HTTPErrorを返すけどレスポンスのBodyを自前のstructで定義したい場合
レスポンスに含まれるのがmessageだけでは物足りないという場合、echo.HTTPErrorのMessageに文字列ではなく構造体をセットすることでレスポンスBodyの内容を変えることができます。
e.GET("/", func(ctx echo.Context) error {
	// return ctx.String(http.StatusOK, "Hello world!")
    // return &echo.HTTPError{Code: http.StatusNotFound, Message: "エラーメッセージ", Internal: errors.New("エラー内容")}
	msgObj := struct {
		Prop1 int
		Prop2 string
	}{
		Prop1: 100,
		Prop2: "AAAAA",
	}
	return &echo.HTTPError{Code: http.StatusNotFound, Message: msgObj, Internal: errors.New("エラー内容")}
})
logの内容です
{"time":"2023-01-22T04:05:37.928444793Z","id":"","remote_ip":"/*remote ip*/","host":"localhost:8888","method":"GET","uri":"/","user_agent":"curl/7.84.0","status":404,"error":"code=404, message={100 AAAAA}, internal=エラー内容","latency":3021208,"latency_human":"3.021208ms","bytes_in":0,"bytes_out":30}
errorのmessage部分が構造体に置き換わっていることが確認できます。
httpレスポンスのBody
{"Prop1":100,"Prop2":"AAAAA"}
狙い通り、構造体をjson化して返してくれています。今回はProp1/Prop2といった形でレスポンスをさせましたが、{"error_code":"~", "message":"~~"}など、レスポンスBodyにmessageだけでなく、サービス固有のエラーIDなどを付け加えたい場合に使えそうです。
2. errorをそのまま返してみる
func e.GET("/", func(ctx echo.Context) error {
	// return ctx.String(http.StatusOK, "Hello world!")
	// return &echo.HTTPError{Code: http.StatusNotFound, Message: "エラーメッセージ", Internal: errors.New("エラー内容")}
	// msgObj := struct {
	// 	Prop1 int
	// 	Prop2 string
	// }{
	// 	Prop1: 100,
	// 	Prop2: "AAAAA",
	// }
	// return &echo.HTTPError{Code: http.StatusNotFound, Message: msgObj, Internal: errors.New("エラー内容")}
	return errors.New("エラー内容")
})
logの内容です
{"time":"2023-01-22T04:13:47.412619673Z","id":"","remote_ip":"/*remote ip*/","host":"localhost:8888","method":"GET","uri":"/","user_agent":"curl/7.84.0","status":500,"error":"エラー内容","latency":832958,"latency_human":"832.958µs","bytes_in":0,"bytes_out":36}
errorの値にはerrors.New()した内容が出力されています
httpレスポンスのBodyです
{"message":"Internal Server Error"}
InternalServerError(StatusCode=500)固定なので400, 401, 404など使い分けをしたい場合は要求を満たせないです。
3. 正常な挙動を装ってInternalServerErrorを返してみる
func e.GET("/", func(ctx echo.Context) error {
	// return ctx.String(http.StatusOK, "Hello world!")
	// return &echo.HTTPError{Code: http.StatusNotFound, Message: "エラーメッセージ", Internal: errors.New("エラー内容")}
	// msgObj := struct {
	// 	Prop1 int
	// 	Prop2 string
	// }{
	// 	Prop1: 100,
	// 	Prop2: "AAAAA",
	// }
	// return &echo.HTTPError{Code: http.StatusNotFound, Message: msgObj, Internal: errors.New("エラー内容")}
	// return errors.New("エラー内容")
	msgObj := struct {
		Prop1 int
		Prop2 string
	}{
		Prop1: 100,
		Prop2: "AAAAA",
	}
	return ctx.JSON(http.StatusInternalServerError, msgObj)
})
logの内容です
{"time":"2023-01-22T04:30:00.244131346Z","id":"","remote_ip":"/*remote ip*/","host":"localhost:8888","method":"GET","uri":"/","user_agent":"curl/7.84.0","status":500,"error":"","latency":1925000,"latency_human":"1.925ms","bytes_in":0,"bytes_out":30}
errorの値は空
httpレスポンスのBodyです
{"Prop1":100,"Prop2":"AAAAA"}
まとめ
DefaultHTTPErrorHandlerを使う前提でのエラー時のログについて
- 
echo.HTTPErrorを返す場合
- 
errorを返す場合
- 
ctx.JSON()で返す場合
それぞれのログ出力を確認しました。
StatusCodeの使い分けやログ出力内容の充実など考えると、echo.HTTPErrorを返すようにするのが良さそうです