こんにちは、極予測やりとりAI というプロダクトの開発責任者をしている しゅん(@MxShun)です。
この記事では、Go の Web フレームワークである Echo で request body と response body をログ出力する方法を紹介します!
目次
結論
さくっとやりたいなら Body Dump を利用する、細かく設定したいなら “ハマりポイント” に注意して ミドルウェアをカスタマイズする とよいです。
Echo におけるミドルウェアとは
Echo におけるミドルウェアは、ビジネスロジック実行前後に処理を差し込める機能です。gRPC でいう Interceptors、Java Servlet でいう Filter に似た機能と聞けばピンとくる方がいるかもしれませんね。
例えば、「クライアントのリクエストを JWT 認証しレスポンスを gzip 圧縮したい」ユースケースがあったとします。JWT 認証ミドルウェアと gzip 圧縮ミドルウェアを用意することで、それらを意識せずにビジネスロジックに集中することができるようになります。
Echo では、いくつかのミドルウェアに加え拡張可能なミドルウェアフレームワークを提供しています。
Feature Overview
- Extensible middleware framework
- Define middleware at root, group or route level
https://github.com/labstack/echo?tab=readme-ov-file#feature-overview
方法1. Body Dump を利用する
Echo が提供するミドルウェアのひとつに Body Dump があります。Body Dump は request body と response body をキャプチャし、[]byte
型で扱えるミドルウェアです。
本記事の主題である「request body と response body をログ出力したい」ユースケースでは、Body Dump 内でログ出力するのが最も近道 です。
e := echo.New()
e.Use(middleware.BodyDump(func(c echo.Context, reqBody, resBody []byte) {
fmt.Printf("request body: %v, response body: %v", string(reqBody), string(resBody))
}))
しかし、実運用において Body Dump でこと足りることはまずないと思います。なぜなら次のようなコンテキスト情報とセットになることで、トレーサビリティを有した実運用で使えるログになるからです。
- リクエスト URI パス
- リクエストメソッド
- レスポンスステータス
方法2. ミドルウェアをカスタマイズする
そこで役に立つミドルウェアに RequestLogger があります。RequestLogger では指定したコンテキストを middleware.RequestLoggerValues
として LogValuesFunc
内でログ出力することができます。
e := echo.New()
e.Use(middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
LogURIPath: true, // リクエスト URI パスを指定
LogMethod: true, // リクエストメソッドを指定
LogStatus: true, // レスポンスステータスを指定
LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
fmt.Printf("request: %s %s, response status: %d", v.Method, v.URIPath, v.Status)
return nil
},
}))
しかし、RequestLogger では request body と response body の指定ができません。(執筆時 v4.12.0 現在)
そこで、Body Dump の実装を参考に RequestLogger をカスタマイズ します。
e := echo.New()
e.Use(requestLogger())
// 中略
func requestLogger() echo.MiddlewareFunc {
var (
reqBody []byte
resBody *bytes.Buffer
)
return middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
LogURIPath: true, // リクエスト URI パスを指定
LogMethod: true, // リクエストメソッドを指定
LogStatus: true, // レスポンスステータスを指定
BeforeNextFunc: func(c echo.Context) {
// Request
reqBody = []byte{}
if c.Request().Body != nil { // Read
reqBody, _ = io.ReadAll(c.Request().Body)
}
c.Request().Body = io.NopCloser(bytes.NewBuffer(reqBody)) // Reset
// Response
resBody = new(bytes.Buffer)
mw := io.MultiWriter(c.Response().Writer, resBody)
writer := &bodyDumpResponseWriter{Writer: mw, ResponseWriter: c.Response().Writer}
c.Response().Writer = writer
},
LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
fmt.Printf("request: %s %s, request body: %v, response status: %d, response body: %v",
v.Method, v.URIPath, string(reqBody), v.Status, resBody.String(),
)
return nil
},
}))
}
type bodyDumpResponseWriter struct {
io.Writer
http.ResponseWriter
}
func (w *bodyDumpResponseWriter) WriteHeader(code int) {
w.ResponseWriter.WriteHeader(code)
}
func (w *bodyDumpResponseWriter) Write(b []byte) (int, error) {
return w.Writer.Write(b)
}
func (w *bodyDumpResponseWriter) Flush() {
err := http.NewResponseController(w.ResponseWriter).Flush()
if err != nil && errors.Is(err, http.ErrNotSupported) {
panic(errors.New("response writer flushing is not supported"))
}
}
func (w *bodyDumpResponseWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) {
return http.NewResponseController(w.ResponseWriter).Hijack()
}
func (w *bodyDumpResponseWriter) Unwrap() http.ResponseWriter {
return w.ResponseWriter
}
このとき注意すべき “ハマりポイント” は、request body のキャプチャと response body を書き込む io.MultiWriter
の準備を BeforeNextFunc
でやっておくこと です。
BeforeNextFunc
は、next(c)
即ち次のミドルウェアまたはビジネスロジック実行前に処理されます。
// BeforeNextFunc defines a function that is called before next middleware or handler is called in chain.
BeforeNextFunc func(c echo.Context)
// 中略
if config.BeforeNextFunc != nil {
config.BeforeNextFunc(c)
}
err := next(c)
LogValuesFunc
は、後段のミドルウェアとビジネスロジック実行後に処理されます。
// LogValuesFunc defines a function that is called with values extracted by logger from request/response.
// Mandatory.
LogValuesFunc func(c echo.Context, v RequestLoggerValues) error
// 中略
if errOnLog := config.LogValuesFunc(c, v); errOnLog != nil {
return errOnLog
}
したがって、RequestLogger の処理の流れは次のようになります。
前述の準備を BeforeNextFunc
でやっておく必要がある理由は、request body は読み切る制御がされていること、response body は直接アクセスするフィールド・メソッドがないため読み取りに工夫が必要なためです。(このあたりは Go http の仕様であり、詳細な記事が既に世に溢れているので説明は割愛します。)
まとめ
今回は Go の Web フレームワークである Echo で request body と response body をログ出力する方法を紹介しました。
方法1. さくっとやりたいなら、Echo が提供する Body Dump を利用しましょう!
方法2. 細かく設定したいなら、request body のキャプチャと response body を書き込む io.MultiWriter
の準備を BeforeNextFunc
でやっておくという “ハマりポイント” に注意して ミドルウェアをカスタマイズする とよいでしょう!
なお、いずれの方法にしても request body と response body に含まれる機密情報・個人情報のマスクやログサイズのチャンクなど、実運用における適正化にもご留意ください。