GoのカスタムRoundTripperでリクエストとレスポンスをログ出力する
はじめに
SaaS開発を行っていると、外部APIとの連携が必要になることが多いです。ここで外部APIとはパブリックに提供されているAPIはもちろん、パートナー企業が提供するAPIや、自社で運用している別のサービスのAPIも含みます。
どのような種類のAPI連携であっても、意図しない挙動がありサポートに問い合わせるとき「自分たちのリクエストがどうだったか」を示すログを提供することで、問題の解決が早まることがあります。
本記事では、http.RoundTripper
を実装し、Observabilityを高める方法を紹介します。
また本記事のサンプルコードは以下にあります。
欲しい情報
Observabilityを考えるとき、基本的には以下の3つが欲しくなると思います。MetricsとTracingはotelを挟むことで簡単に取得できるので、ここではLoggingにフォーカスします。
-
Logging
- どのようなリクエストを送信し、どのようなレスポンスを受信したか記録する。
-
Metrics
- 外部APIのレスポンスタイム、成功/失敗率を収集し、パフォーマンスを監視する。
-
Tracing
- 1つのリクエストがどのように処理され、どのAPIとやりとりしたかを可視化する。
http.RoundTripperについて
Goでは http.RoundTripper
インターフェースを実装して、それをHTTPクライアントに差し込むことで振る舞いをカスタマイズすることができます。
type RoundTripper interface {
RoundTrip(*http.Request) (*http.Response, error)
}
シンプルな例として、HTTPリクエストを送信する際に固定の文字列をログ出力するRoundTripperを実装してみます。
var _ http.RoundTripper = &SimpleRoundTripper{}
type SimpleRoundTripper struct {}
func (rt *SimpleRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
log.Println("Sending request")
return http.DefaultTransport.RoundTrip(req)
}
これを使って、以下のようにリクエストを送信すると Sending request
というログが出力されます。
client := &http.Client{
Transport: &SimpleRoundTripper{},
}
client.Get("http://example.com")
$ go run .
2025/01/31 08:50:48 Sending request
LoggingRoundTripperの実装
ここまででRoundTripperを実装する方法がわかったので、リクエストとレスポンスの内容をログ出力するLoggingRoundTripperを実装してみます。
基本的なアイデアは、httputilパッケージの DumpRequestOut
と DumpResponse
を使ってリクエストとレスポンスを文字列に変換し、それをログ出力することです。
type LoggingRoundTripper struct {}
func (lrt *LoggingRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
ctx := req.Context()
clone := req.Clone(ctx)
b, err := io.ReadAll(clone.Body)
if err != nil {
return nil, fmt.Errorf("failed to read request body: %w", err)
}
defer clone.Body.Close()
// 元リクエストのBodyをリストア
req.Body = io.NopCloser(bytes.NewReader(b))
// dump request
clone.Body = io.NopCloser(bytes.NewReader(b))
reqDump, err := httputil.DumpRequestOut(clone, true)
if err != nil {
return nil, fmt.Errorf("httputil.DumpRequestOut: %w", err)
}
log.Println(string(reqDump))
resp, err := http.DefaultTransport.RoundTrip(req)
if err != nil {
return nil, fmt.Errorf("http.DefaultTransport.RoundTrip: %w", err)
}
// dump response
respDump, err := httputil.DumpResponse(resp, true)
if err != nil {
return nil, fmt.Errorf("httputil.DumpResponse: %w", err)
}
log.Println(string(respDump))
return resp, nil
}
bodyはログ出力用にバッファを分けることで、元リクエストには影響を与えないようにしています。
これを使って、以下のようにリクエストを送信するとリクエストとレスポンスの内容がログ出力されます。
client := &http.Client{
Transport: &LoggingRoundTripper{},
}
body := map[string]string{
"username": "user",
"password": "password",
}
b, err := json.Marshal(body)
if err != nil {
return err
}
req, err := http.NewRequestWithContext(context.Background(), "POST", "https://httpbin.org/post", bytes.NewReader(b))
if err != nil {
return err
}
req.Header.Set("Content-Type", "application/json")
_, err = client.Do(req)
httpbin.org宛のリクエストと、その後にレスポンスのダンプが出力されていることが分かります。
$ go run .
2025/01/31 09:18:46 POST /post HTTP/1.1
Host: httpbin.org
User-Agent: Go-http-client/1.1
Content-Length: 41
Content-Type: application/json
Accept-Encoding: gzip
{"password":"password","username":"user"}
2025/01/31 09:18:47 HTTP/2.0 200 OK
Content-Length: 509
Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: *
Content-Type: application/json
Date: Fri, 31 Jan 2025 00:18:47 GMT
Server: gunicorn/19.9.0
{
"args": {},
"data": "{\"password\":\"password\",\"username\":\"user\"}",
"files": {},
"form": {},
"headers": {
"Accept-Encoding": "gzip",
"Content-Length": "41",
"Content-Type": "application/json",
"Host": "httpbin.org",
"User-Agent": "Go-http-client/2.0",
"X-Amzn-Trace-Id": "Root=1-679c16e7-536069b67dfefd0539c87ed2"
},
"json": {
"password": "password",
"username": "user"
},
"origin": "217.178.16.153",
"url": "https://httpbin.org/post"
}
機密情報をマスクする
先の例ではbodyにpasswordを含めていましたが、これは機密情報であるためログに残すべきではありません。ということで任意のキーに対してマスクを行う機能を追加してみます。
こちらは github.com/tidwall/gjson
と github.com/tidwall/sjson
を使ってjsonのフィールドをマスクすることで実現してみます。
また何のフィールドをマスクするかはLoggingRoundTripperのフィールドとして指定できるようにしてみます。
4a5
> "encoding/json"
9a11,13
>
> "github.com/tidwall/gjson"
> "github.com/tidwall/sjson"
12c16,18
< type LoggingRoundTripper struct{}
---
> type LoggingRoundTripper struct {
> MaskFields []string
> }
28c34,38
< clone.Body = io.NopCloser(bytes.NewReader(b))
---
> maskedBody, err := maskJSONFields(b, lrt.MaskFields)
> if err != nil {
> return nil, fmt.Errorf("failed to mask request body: %w", err)
> }
> clone.Body = io.NopCloser(bytes.NewReader(maskedBody))
> clone.ContentLength = int64(len(maskedBody))
> clone.Header.Set("Content-Length", fmt.Sprint(len(maskedBody)))
48a59,78
>
> // maskJSONFields request bodyの指定されたフィールドをマスクする. bodyがJSONでない場合は何もしない
> func maskJSONFields(body []byte, fieldsToMask []string) ([]byte, error) {
> if ok := json.Valid(body); !ok {
> return body, nil
> }
>
> maskedBody := string(body)
> var err error
> for _, field := range fieldsToMask {
> if !gjson.Get(maskedBody, field).Exists() {
> continue
> }
> maskedBody, err = sjson.Set(maskedBody, field, "***")
> if err != nil {
> return nil, fmt.Errorf("failed to mask field: %w", err)
> }
> }
> return []byte(maskedBody), nil
> }
ここで MaskFields
にpasswordを指定してリクエストを送信すると、以下のようにpasswordがマスクされていることが分かります。
$ go run .
2025/01/31 09:28:16 Sending request
2025/01/31 09:28:16 POST /post HTTP/1.1
Host: httpbin.org
User-Agent: Go-http-client/1.1
Content-Length: 36
Content-Type: application/json
Accept-Encoding: gzip
{"password":"***","username":"user"}
...
まとめ
Goの http.RoundTripper
を使って、リクエストとレスポンスの内容をログ出力するLoggingRoundTripperを実装しました。
また、特定のフィールドをマスクすることで、機密情報などの扱いに対応しました。
このようなカスタムRoundTripperを使うことで、外部APIとの連携においてObservability向上に役立てることができます。
実際にはotelhttpなどと組み合わせて利用しているので、Transportを差し込めるようにしていたりしますが、最低限の実装としては今回紹介した形で充分だと思います。
ログを出力するだけだと検索しづらいので、手前味噌ですが以下のような手法を使ってトレースIDと紐付けるのがオススメです。
Discussion