26/03/2020 - GO
In this example we are going to use httptrace to obtain information related to HTTP client request and print it for debugging purposes. The tracing will start from DNS lookup and go all the way to receiving the response. Finally we will print the result in JSON format. This could be good if you wanted to debug HTTP client issues.
package main
import (
"crypto/tls"
"encoding/json"
"fmt"
"io/ioutil"
"log"
"net"
"net/http"
"net/http/httptrace"
"time"
)
type Debug struct {
DNS struct{
Start string `json:"start"`
End string `json:"end"`
Host string `json:"host"`
Address []net.IPAddr `json:"address"`
Error error `json:"error"`
} `json:"dns"`
Dial struct{
Start string `json:"start"`
End string `json:"end"`
} `json:"dial"`
Connection struct{
Time string `json:"time"`
} `json:"connection"`
WroteAllRequestHeaders struct{
Time string `json:"time"`
} `json:"wrote_all_request_header"`
WroteAllRequest struct{
Time string `json:"time"`
} `json:"wrote_all_request"`
FirstReceivedResponseByte struct{
Time string `json:"time"`
} `json:"first_received_response_byte"`
}
func main() {
// Create trace struct.
trace, debug := trace()
// Prepare request with trace attached to it.
req, err := http.NewRequest(http.MethodGet, "http://localhost:8090/server/api/v1/users", nil)
if err != nil {
log.Fatalln("request error", err)
}
req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))
// MAke a request.
res, err := client().Do(req)
if err != nil {
log.Fatalln("client error", err)
}
defer res.Body.Close()
// Read response.
body, err := ioutil.ReadAll(res.Body)
if err != nil {
log.Fatal(err)
}
// Print report.
data, err := json.MarshalIndent(debug, "", " ")
fmt.Println(string(data))
fmt.Println(string(body))
}
func client() *http.Client {
return &http.Client{
Transport: transport(),
}
}
func transport() *http.Transport {
return &http.Transport{
DisableKeepAlives: true,
TLSClientConfig: tlsConfig(),
}
}
func tlsConfig() *tls.Config {
return &tls.Config{
InsecureSkipVerify: true,
}
}
func trace() (*httptrace.ClientTrace, *Debug) {
d := &Debug{}
t := &httptrace.ClientTrace{
DNSStart: func(info httptrace.DNSStartInfo) {
t := time.Now().UTC().String()
log.Println(t, "dns start")
d.DNS.Start = t
d.DNS.Host = info.Host
},
DNSDone: func(info httptrace.DNSDoneInfo) {
t := time.Now().UTC().String()
log.Println(t, "dns end")
d.DNS.End = t
d.DNS.Address = info.Addrs
d.DNS.Error = info.Err
},
ConnectStart: func(network, addr string) {
t := time.Now().UTC().String()
log.Println(t, "dial start")
d.Dial.Start = t
},
ConnectDone: func(network, addr string, err error) {
t := time.Now().UTC().String()
log.Println(t, "dial end")
d.Dial.End = t
},
GotConn: func(connInfo httptrace.GotConnInfo) {
t := time.Now().UTC().String()
log.Println(t, "conn time")
d.Connection.Time = t
},
WroteHeaders: func() {
t := time.Now().UTC().String()
log.Println(t, "wrote all request headers")
d.WroteAllRequestHeaders.Time = t
},
WroteRequest: func(wr httptrace.WroteRequestInfo) {
t := time.Now().UTC().String()
log.Println(t, "wrote all request")
d.WroteAllRequest.Time = t
},
GotFirstResponseByte: func() {
t := time.Now().UTC().String()
log.Println(t, "first received response byte")
d.FirstReceivedResponseByte.Time = t
},
}
return t, d
}
2020/03/26 18:11:28 2020-03-26 18:11:28.699923 +0000 UTC dns start
2020/03/26 18:11:28 2020-03-26 18:11:28.703246 +0000 UTC dns end
2020/03/26 18:11:28 2020-03-26 18:11:28.703556 +0000 UTC dial start
2020/03/26 18:11:28 2020-03-26 18:11:28.704488 +0000 UTC dial end
2020/03/26 18:11:28 2020-03-26 18:11:28.705182 +0000 UTC conn time
2020/03/26 18:11:28 2020-03-26 18:11:28.705841 +0000 UTC wrote all request headers
2020/03/26 18:11:28 2020-03-26 18:11:28.705920 +0000 UTC wrote all request
2020/03/26 18:11:28 2020-03-26 18:11:28.707156 +0000 UTC first received response byte
{
"dns": {
"start": "2020-03-26 18:11:28.699923 +0000 UTC",
"end": "2020-03-26 18:11:28.703246 +0000 UTC",
"host": "localhost",
"address": [
{
"IP": "::1",
"Zone": ""
},
{
"IP": "127.0.0.1",
"Zone": ""
}
],
"error": null
},
"dial": {
"start": "2020-03-26 18:11:28.703556 +0000 UTC",
"end": "2020-03-26 18:11:28.704488 +0000 UTC"
},
"connection": {
"time": "2020-03-26 18:11:28.705182 +0000 UTC"
},
"wrote_all_request_header": {
"time": "2020-03-26 18:11:28.705841 +0000 UTC"
},
"wrote_all_request": {
"time": "2020-03-26 18:11:28.705920 +0000 UTC"
},
"first_received_response_byte": {
"time": "2020-03-26 18:11:28.707156 +0000 UTC"
}
}
real server responding: 2020-03-26 18:11:28.706893 +0000 UTC