CODEWITHSUNDEEP
gologging
kargirwar
kargirwar

Reputation: 598

Tracing golang http request

I want to trace complete execution of an HTTP request in golang. For any non trivial operation the request will eventually call many different functions. I would like to have logs from the entire execution stack tagged with a unique request id. e.g.

http.Handle("/my-request", myrequesthandler)
func myrequestHandler(w http.ResponseWriter, r *http.Request) {

        //debug print1
        log.Printf("....")
        myfunc()
}

func myfunc() {
        //debug print2
        log.Printf("....")
}

Here I need a way to identify print1 and print2 as part of same request. It looks like zerolog does have something like this, as described here. Like so:

....
c = c.Append(hlog.RequestIDHandler("req_id", "Request-Id"))
h := c.Then(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
   
    hlog.FromRequest(r).Info().
        Msg("Something happened")

}))
http.Handle("/", h)

But if I understand it right, it will involve passing request object to each and every function. Is this the idiomatic way to solve this problem? What are the alternatives?

Upvotes: 2

Views: 4301

Answers (2)

Bicky Eric Cantona
Bicky Eric Cantona

Reputation: 44

you can use context.Context and set request id on it via middleware function.
example:

type requestIDKey struct{}

func requestIDSetter(next http.HandlerFunc) http.HandlerFunc {
    return func(rw http.ResponseWriter, r *http.Request) {
        // use provided request id from incoming request if any
        reqID := r.Header.Get("X-Request-ID")
        if reqID == "" {
            // or use some generated string
            reqID = uuid.New().String()
        }
        ctx := context.WithValue(r.Context(), requestIDKey{}, reqID)

        next(rw, r.WithContext(ctx))
    }
}

then you need to modify your logger to accept context.Context
example:

func printfWithContext(ctx context.Context, format string, v ...interface{}) {
    reqID := ctx.Value(requestIDKey{}).(string)
    log.Printf(reqID+": "+format, v...)
}

and finally apply to your code

http.HandleFunc("/my-request", requestIDSetter(myrequestHandler))

func myrequestHandler(w http.ResponseWriter, r *http.Request) {
    ctx := r.Context()

    //debug print1
    printfWithContext(ctx, "....1")
    myfunc(ctx)
}

func myfunc(ctx context.Context) {
    //debug print2
    printfWithContext(ctx, "....2")
}

Upvotes: 1

blackgreen
blackgreen

Reputation: 45219

Set a unique id on a context.Context as soon as the request is received, and pass that context down the call stack. This is what contexts are for.

[Context] carries deadlines, cancellation signals, and other request-scoped values across API boundaries and between processes.

Example:

// You could place this in a separate helper package to improve encapsulation
type ctxKey struct{}

func myRequestHandler(w http.ResponseWriter, r *http.Request) {
    uniqueID := // generate a unique identifier 

    // create a context with the http.Request context as parent
    ctx := context.WithValue(r.Context(), ctxKey{}, uniqueID)
    
    foo(ctx, ...)
    bar(ctx, ...)
}

func foo(ctx context.Context, ...) {
    uniqueID := ctx.Value(ctxKey{})
    // do something with the unique id
    baz(ctx, ...)
}

In particular:

  • Create the context with *http.Request.Context() as parent. This way if the request is canceled, e.g. due to client disconnection, cancellation will propagate to your sub-context
  • Consider setting the context value using an unexported struct as key. Unexported structs defined in your package will never conflict with other keys. If you use strings as keys instead, any package could in theory use the same key and overwrite your value (or you could overwrite others' values). YMMV.
  • Pass your context as the first argument of any function in your call stack, as the package documentation recommends.

For tracing and logging across applications, you might want to look into opentracing. Propagation of tracers is still done with Contexts as outlined above.

Upvotes: 3

Related Questions