Go 1.7 httptrace and context debug patterns

Package httptrace is a new addition in Go 1.7 that allows users to trace the steps of a HTTP request. This package also models an interesting design pattern around adding optional debugging to a library. However, it’s not the only way to accomplish this goal. I’ll briefly overview the package and provide alternative implementations for httptrace.

httptrace

The basic idea of httptrace is that a laundry list of callbacks are optionally attached to a Context object that is added to a HTTP request. During the inner workings of the request, if any of these callbacks are set, they are called during different stages of the request.

An illustrative example of httptrace is below, with a playground link at https://play.golang.org/p/pVVBcrSklg.

Output

Starting request!
Dial start
Dial done
Got Conn
Wrote headers
Wrote request {<nil>}
First response byte!
404 page not found
Done!

The trace object on line 21 is the important object, with it being attached on line 41. The full ClientTrace object is interesting to look at and pretty self explanatory:

You can see where it’s actually used inside request.go. For example, this code is right after the request sends the final “\r\n” for the request headers.

Is this appropriate use of Context.Value?

My previous post, How to correctly use context.Context in Go 1.7, talks a bit about how to correctly use context.Value. In particular, the primary point is that the content of context.Value is for maintainers not users. This point fits perfectly with the implementation of httptrace. The intended use of httptrace is purely for debugging and tracking, allowing the caller to time functions or debug a misbehaving http request.

Poorly designed implementations of httptrace

It was possible to design httptrace in a way that it did more than inform. For example, consider the following implementation.

This alternative implementation modifies the original GetConn callback to allow users to change the net.Conn the client uses. Unfortunately, this allows a large amount of control over the request and moves use of ClientTrace from inform to control. With such strong control of the request, this API would make more sense in the http.Request object than inside Context.Value. Consider another implementation.

This debugging implementation allows users to modify the context during a callback, maybe adding values to it. While initially useful, it also injects logic into the current request. This is less bad than the above situation, but still closer to control than inform.

Again, the important part of httptrace’s implementation is that the callbacks don’t situate themselves for injecting logic control.

Alternatives to httptrace’s implementation

Put ClientTrace on the request

One alternative implementation is to put ClientTrace on the http.Request object rather than hide it in the Context.

This would have accomplished the same goal. Unfortunately, exposing debugging so prominently in an API looks ugly to our human eyes. There is a reasonable goal of making http.Client as simple as possible, and one aspect of simplicity is limiting options. Debugging isn’t a requirement of Client’s API, but it’s a reality of needing to understand why your system isn’t working. Putting it in the context hides this option from view. In other words, quoting my previous context article.

Putting this debug information in a Context object is a compromise between the perfect API that would never need maintenance and the realities of wanting to thread debug information across an API.

Even given this justification of putting HttpTrace inside a context, it still would have been reasonable to place it in the Request object directly.

Use a logger

Imagine if ClientTrace looked like the following.

In this case, rather than call ClientTrace.GetConn, the library calls ClientTrace.Log(“GetConn”). Many third-party libraries in Go do something similar, attaching an optional debug logger inside the context of a request. The Log function can either print out GetConn, or just do a time.Now() request to see how long it took to get to the state GetConn. Log and Callback designs are the same goal, but on a spectrum. In your own libraries, you could remove all loggers and just do what ClientTrace does, replacing them all with Callbacks at each specific Log statement. This is not commonly done because it can get a bit tedious to iterate on. Consider the following questions when deciding between a Log based and Callback based design for debugging.

  • Callback based designs require a more stable API. Log based designs can be more flexible.
  • Users don’t get all new callbacks implicitly. With Log designs, any new Log statements are all captured
  • Callback designs tend to be more strongly typed.
  • Callback designs are documented. While you could document the exact Log statements you will call, generally what things are logged is implied as unstable API.
  • Callback designs are more tedious to capture all of them. A single logger would get all Log statements, but to get all Callbacks you need many lines of code.

Add your own debuggers

Debugging and understanding the performance and flow of code is critical to maintaining software. Adding debugging callbacks to your own requests goes a long way to helping people understand what is going on when they use your library. Deciding between a log based or callback based design is up to you. Where to attach these hooks, on the Context or a request object, is also up to you. But please, let me debug your library!