golang echoでRequest/Response Bodyをログに出力

goで[echo](https://github.com/labstack/echo)を使った際に Request/ResponseのBody内容 (正常時/エラー時)をログに出力したい要件があったので、やり方のメモです。

## 結論
middleware.BodyDumpを使う

## やり方
### 正常時
サンプルコードを以下に記載します。

```main.go

package main

import (
  "fmt"
  "net/http"

  "github.com/labstack/echo"
  "github.com/labstack/echo/middleware"
)

type Response struct {
	Status  int
	Message string
}

func bodyDumpHandler(c echo.Context, reqBody, resBody []byte) {
  fmt.Printf("Request Body: %v\n", string(reqBody))
  fmt.Printf("Response Body: %v\n", string(resBody))
}

func main() {
  e := echo.New()

  e.Use(middleware.BodyDump(bodyDumpHandler))

  e.POST("/yorimoi", func(c echo.Context) error {
    return c.JSON(http.StatusOK, Response{
			Status:  http.StatusOK,
			Message: "They got to the Antarctica!",
		})
	})

  e.Logger.Fatal(e.Start(":1323"))

}
```

上記コードの `e.Use(middleware.BodyDump(bodyDumpHandler))`
といったように middleware.BodyDumpにHandler関数を設定します。

Handler関数では `reqBody, resBody`をbyte配列で受け取ります。
サンプルコードでは標準出力にRequest/ResponseのBodyを出力しています。

試しに以下のリクエストを投げてみます。

```json
[
	"玉木 マリ",
	"小淵沢 報瀬",
	"三宅 日向",
	"白石 結月"
]
```

標準出力に以下のような出力が得られました。

```sh
Request Body: [
	"玉木まり",
	"小淵沢 報瀬",
	"三宅 日向",
	"白石 結月"
]
Response Body: {"Status":200,"Message":"They got to the Antarctica!"}
```

### エラー時

エラー時のハンドリングには HTTPErrorHandlerを設定する必要がありますね。

エラー時のサンプルコードを以下に記載します。

```main.go

package main

import (
	"fmt"
	"net/http"

	"github.com/labstack/echo"
	"github.com/labstack/echo/middleware"
)

type Response struct {
	Status  int
	Message string
}

func bodyDumpHandler(c echo.Context, reqBody, resBody []byte) {
	fmt.Printf("Request Body: %v\n", string(reqBody))
	fmt.Printf("Response Body: %v\n", string(resBody))
}

func main() {
	e := echo.New()

	e.Use(middleware.BodyDump(bodyDumpHandler))

	e.HTTPErrorHandler = func(err error, c echo.Context) {
		if he, ok := err.(*echo.HTTPError); ok {
			c.JSON(he.Code, Response{
				Status:  he.Code,
				Message: he.Error(),
			})
		}
	}

	e.POST("/yorimoi", func(c echo.Context) error {
		var crew []string
		c.Bind(&crew)
		if len(crew) < 4 {
			return echo.NewHTTPError(http.StatusBadRequest, "Going by 4 people is top priority!")
		}

		return c.JSON(http.StatusOK, Response{
			Status:  http.StatusOK,
			Message: "They got to the Antarctica!",
		})
	})

	e.Logger.Fatal(e.Start(":1323"))

}
```

以下のリクエストを投げてみます。(一人足りない)

```json
[
	"玉木まり",
	"小淵沢 報瀬",
	"白石 結月"
]
```

標準出力に以下のようなエラー時の出力が得られました。

```sh
Request Body: [
		"玉木まり",
		"小淵沢 報瀬",
		"白石 結月"
]
Response Body: {"Status":400,"Message":"code=400, message=Going by 4 people is top priority!"}
```


が！このとき、http Responseは以下のような出力になっています。

```sh
{"Status":400,"Message":"code=400, message=Going by 4 people is top priority!"}{"Status":400,"Message":"code=400, message=Going by 4 people is top priority!"}
```

同じオブジェクトが連結されている。。

これはmiddleware.BodyDumpを使用した場合に
HTTP response headerを書き込む前と書き込んだ後にHTTPErrorHandlerを２度通過してしまうからです。

これを回避するためにHTTPErrorHandlerの中で `c.Response().Committed`を使って、書き込まれたかどうかを判定しましょう。

以下がコード全文です。

```main.go
package main

import (
	"fmt"
	"net/http"

	"github.com/labstack/echo"
	"github.com/labstack/echo/middleware"
)

type Response struct {
	Status  int
	Message string
}

func bodyDumpHandler(c echo.Context, reqBody, resBody []byte) {
	fmt.Printf("Request Body: %v\n", string(reqBody))
	fmt.Printf("Response Body: %v\n", string(resBody))
}

func main() {
	e := echo.New()

	e.Use(middleware.BodyDump(bodyDumpHandler))

	e.HTTPErrorHandler = func(err error, c echo.Context) {
		if c.Response().Committed {
			return
		}
		if he, ok := err.(*echo.HTTPError); ok {
			c.JSON(he.Code, Response{
				Status:  he.Code,
				Message: he.Error(),
			})
		}
	}

	e.POST("/yorimoi", func(c echo.Context) error {
		var crew []string
		c.Bind(&crew)
		if len(crew) < 4 {
			return echo.NewHTTPError(http.StatusBadRequest, "Going by 4 people is top priority!")
		}

		return c.JSON(http.StatusOK, Response{
			Status:  http.StatusOK,
			Message: "They got to the Antarctica!",
		})
	})

	e.Logger.Fatal(e.Start(":1323"))

}
```

無事、以下のようなResponseを得ました。

```sh
{"Status":400,"Message":"code=400, message=Going by 4 people is top priority!"}
```


４人で行くの！この４人で！
それが最優先だから！