結論

さくっとやりたいなら 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 に含まれる機密情報・個人情報のマスクやログサイズのチャンクなど、実運用における適正化にもご留意ください。

AIを駆使したゲーム開発戦略: 新設AI組織の取り組み [CADC2024]

ゲーム開発における、Figma活用事例の紹介 [CADC2024]

GoのEchoフレームワークでrequest bodyとresponse bodyをログ出力する

目次

結論

Echo におけるミドルウェアとは

方法1. Body Dump を利用する

方法2. ミドルウェアをカスタマイズする

まとめ