Tracing HTTP request latency in golang
reorx/httpstat ( and followed @davecheney’s golang implementation ) is getting hot recently ( there is also node implementation !) . It’s very useful to see these latency with intuitive way in console when something wrong happens on network.
While contributing the project, I thought it’s very useful if I can output the same information on my own golang HTTP client ( or my network connected CLI tool ) when debugging. So I wrote a small package to do this, https://github.com/tcnksm/go-httpstat .
Because it creates a httptrace powered `context.Context`, you just need to pass it to your `http.Request` by `withContext()` method ( So must be less code modification !).
The following is an example usage of this package (trace request to https://github.com ).
// Create a new HTTP request
req, err := http.NewRequest("GET", "https://github.com", nil)
if err != nil {
log.Fatal(err)
}// Create a httpstat powered context
var result httpstat.Result
ctx := httpstat.WithHTTPStat(req.Context(), &result)
req = req.WithContext(ctx)// Send request by default HTTP client
client := http.DefaultClient
res, err := client.Do(req)
if err != nil {
log.Fatal(err)
}if _, err := io.Copy(ioutil.Discard, res.Body); err != nil {
log.Fatal(err)
}
res.Body.Close()
end := time.Now()// Show the results
log.Printf("DNS lookup: %d ms", int(result.DNSLookup/time.Millisecond))
log.Printf("TCP connection: %d ms", int(result.TCPConnection/time.Millisecond))
log.Printf("TLS handshake: %d ms", int(result.TLSHandshake/time.Millisecond))
log.Printf("Server processing: %d ms", int(result.ServerProcessing/time.Millisecond))
log.Printf("Content transfer: %d ms", int(result.ContentTransfer(time.Now())/time.Millisecond))
The result of this is like below,
2016/09/27 17:58:38 DNS lookup: 5 ms
2016/09/27 17:58:38 TCP connection: 180 ms
2016/09/27 17:58:38 TLS handshake: 461 ms
2016/09/27 17:58:38 Server processing: 296 ms
2016/09/27 17:58:38 Content transfer: 180 ms