How to log HTTP client's requests with request ID that was created by Gin context

Question

Idea: I want to log incoming and outcoming requests to my Gin server with unique request ID. Also I want to log all HTTP client's requests inside my Gin's routes using the same request ID that route has.

All of that should to work under the hood using middleware.

Logging requests to my server (and responses)

To log each request to my server I wrote this middleware:

import (
    "bytes"
    "context"
    "github.com/gin-contrib/requestid"
    "github.com/gin-gonic/gin"
    "github.com/rs/zerolog/log"
    "io/ioutil"
    "net/http"
    "time"
)

type responseBodyWriter struct {
    gin.ResponseWriter
    body *bytes.Buffer
}

func (r responseBodyWriter) Write(b []byte) (int, error) {
    r.body.Write(b)
    return r.ResponseWriter.Write(b)
}

func LoggerMiddleware() gin.HandlerFunc {
    return func(c *gin.Context) {

        start := time.Now()

        w := &responseBodyWriter{body: &bytes.Buffer{}, ResponseWriter: c.Writer}
        c.Writer = w

        msg := "Input:"
        path := c.Request.URL.Path
        raw := c.Request.URL.RawQuery
        if raw != "" {
            path = path + "?" + raw
        }

        // Read from body and write here again.
        var bodyBytes []byte
        if c.Request.Body != nil {
            bodyBytes, _ = ioutil.ReadAll(c.Request.Body)
        }
        c.Request.Body = ioutil.NopCloser(bytes.NewBuffer(bodyBytes))

        inputLogger := log.With().
            Str("method", c.Request.Method).
            Str("path", path).
            Str("requestId", requestid.Get(c)).
            Logger()

        if len(bodyBytes) > 0 {
            inputLogger.Info().RawJSON("body", bodyBytes).Msg(msg)
        } else {
            inputLogger.Info().Msg(msg)
        }

        c.Next()

        end := time.Now()
        latency := end.Sub(start)

        msg = "Output:"
        outputLogger := log.With().
            Str("method", c.Request.Method).
            Str("path", path).
            Str("requestId", requestid.Get(c)).
            RawJSON("body", w.body.Bytes()).
            Int("status", c.Writer.Status()).
            Dur("latency", latency).
            Logger()

        switch {
        case c.Writer.Status() >= http.StatusBadRequest && c.Writer.Status() < http.StatusInternalServerError:
            {
                outputLogger.Warn().Msg(msg)
            }
        case c.Writer.Status() >= http.StatusInternalServerError:
            {
                outputLogger.Error().Msg(msg)
            }
        default:
            outputLogger.Info().Msg(msg)
        }

    }
}

Logging requests made inside my servers route

Here is the problem: I don't know how to pass request ID (or Gin's context), created by Gin's middleware to the RoundTrip function:

type Transport struct {
    Transport  http.RoundTripper
}

var defaultTransport = Transport{
    Transport: http.DefaultTransport,
}

func init() {
    http.DefaultTransport = &defaultTransport
}

func (t *Transport) RoundTrip(req *http.Request) (*http.Response, error) {
    ctx := context.WithValue(req.Context(), ContextKeyRequestStart, time.Now())
    req = req.WithContext(ctx)
    t.logRequest(req)

    resp, err := t.transport().RoundTrip(req)
    if err != nil {
        return resp, err
    }

    t.logResponse(resp)

    return resp, err
}

func (t *Transport) logRequest(req *http.Request) {
    log.Info().
        Str("method", req.Method).
        Str("path", req.URL.String()).
        Str("requestId", "how can I get request id here???").
        Msg("Api request: ")
}

func (t *Transport) logResponse(resp *http.Response) {
    var bodyBytes []byte
    if resp.Body != nil {
        bodyBytes, _ = ioutil.ReadAll(resp.Body)
    }
    resp.Body = ioutil.NopCloser(bytes.NewBuffer(bodyBytes))

    ctx := resp.Request.Context()
    log.Info().
        Str("method", resp.Request.Method).
        Str("path", resp.Request.URL.String()).
        Str("requestId", "how can I get request id here???").
        RawJSON("body", bodyBytes).
        Int("status", resp.StatusCode).
        Dur("latency", time.Now().Sub(ctx.Value(ContextKeyRequestStart).(time.Time))).
        Msg("API response: ")
}

func (t *Transport) transport() http.RoundTripper {
    if t.Transport != nil {
        return t.Transport
    }

    return http.DefaultTransport
}

Answer 1

You can use this:
https://github.com/sumit-tembe/gin-requestid

package main

import (
    "net/http"

    "github.com/gin-gonic/gin"
    requestid "github.com/sumit-tembe/gin-requestid"
)

func main() {
    // without any middlewares
    router := gin.New()

    // Middlewares
    {
        //recovery middleware
        router.Use(gin.Recovery())
        //middleware which injects a 'RequestID' into the context and header of each request.
        router.Use(requestid.RequestID(nil))
        //middleware which enhance Gin request logger to include 'RequestID'
        router.Use(gin.LoggerWithConfig(requestid.GetLoggerConfig(nil, nil, nil)))
    }

    router.GET("/", func(c *gin.Context) {
        c.String(http.StatusOK, "Hello world!")
    })

    router.Run(":8080")
}

Output:

[GIN-debug] 2019-12-16T18:50:49+05:30 [bzQg6wTpL4cdZ9bM] - "GET /"
[GIN-debug] 2019-12-16T18:50:49+05:30 [bzQg6wTpL4cdZ9bM] - [::1] "GET / HTTP/1.1 200 22.415µs" Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.108 Safari/537.36

It also supports custom request id generator which you can design according to need.

Answer 2

The Transport.RoundTrip function takes a *http.Request parameter, so you should be able to pass the Gin context by just creating a request in your handlers with it:

func MyHandler(c *gin.Context) {
        // passing context to the request
        req := http.NewRequestWithContext(c, "GET", "http://localhost:8080", nil)
        resp, err := http.DefaultClient.Do(req)
}

Note that to be able to make use of the default RoundTripper that you overwrote without additional initialization, you should use the http.DefaultClient.