diff --git a/config.go b/config.go index 48d5e9e..5e5cd26 100644 --- a/config.go +++ b/config.go @@ -79,6 +79,8 @@ type ( Client *http.Client Request *http.Request + + clientTrace *clientTrace } ) @@ -279,6 +281,9 @@ func (rc *RequestConfig) mergeConfig(config *Config) *RequestConfig { } } } + + rc.clientTrace = &clientTrace{} + rc.Context = rc.clientTrace.createContext(rc.Context) return rc } diff --git a/examples/github.go b/examples/github.go index aa6b87c..6f7b804 100644 --- a/examples/github.go +++ b/examples/github.go @@ -54,6 +54,7 @@ func (api *GithubApi) GetRepo(OWNER, REPO string) (info *GithubRepoInfo, err err if err != nil { return } + fmt.Printf("GetRepo perf: %+v\n", resp.Performance) return info, resp.Json(&info) } diff --git a/performance.go b/performance.go index 82c6494..a28400e 100644 --- a/performance.go +++ b/performance.go @@ -1,18 +1,74 @@ package surf -import "time" +import ( + "time" +) // Performance represents the response performance metrics. type Performance struct { - ResponseTime time.Duration // ResponseTime is the duration of the response. -} + clientTrace *clientTrace + + // DNSLookup is a duration that transport took to perform + DNSLookup time.Duration + + // ConnTime is a duration that took to obtain a successful connection. + ConnTime time.Duration + + // TCPConnTime is a duration that took to obtain the TCP connection. + TCPConnTime time.Duration + + // TLSHandshake is a duration that TLS handshake took place. + TLSHandshake time.Duration + + // ServerTime is a duration that server took to respond first byte. + ServerTime time.Duration + + // ResponseTime is a duration since first response byte from server to + ResponseTime time.Duration + + // TotalTime is a duration that total request took end-to-end. + TotalTime time.Duration -// newPerformance creates a new Performance instance. -func newPerformance() *Performance { - return &Performance{} + // IsConnReused is whether this connection has been previously + IsConnReused bool + + // IsConnWasIdle is whether this connection was obtained from an + IsConnWasIdle bool + + // ConnIdleTime is a duration how long the connection was previously + ConnIdleTime time.Duration } -// recordResponseTime records the duration of the response based on the start time. -func (p *Performance) recordResponseTime(startTime time.Time) { - p.ResponseTime = time.Since(startTime) +func (p *Performance) record() { + ct := p.clientTrace + + ct.endTime = time.Now() + p.DNSLookup = ct.dnsDone.Sub(ct.dnsStart) + p.TLSHandshake = ct.tlsHandshakeDone.Sub(ct.tlsHandshakeStart) + p.ServerTime = ct.gotFirstResponseByte.Sub(ct.gotConn) + p.IsConnReused = ct.gotConnInfo.Reused + p.IsConnWasIdle = ct.gotConnInfo.WasIdle + p.ConnIdleTime = ct.gotConnInfo.IdleTime + + // when connection is reused + if ct.gotConnInfo.Reused { + p.TotalTime = ct.endTime.Sub(ct.getConn) + } else { + p.TotalTime = ct.endTime.Sub(ct.dnsStart) + } + + // Only calculate on successful connections + if !ct.connectDone.IsZero() { + p.TCPConnTime = ct.connectDone.Sub(ct.dnsDone) + } + + // Only calculate on successful connections + if !ct.gotConn.IsZero() { + p.ConnTime = ct.gotConn.Sub(ct.getConn) + } + + // Only calculate on successful connections + if !ct.gotFirstResponseByte.IsZero() { + p.ResponseTime = ct.endTime.Sub(ct.gotFirstResponseByte) + } } diff --git a/surf.go b/surf.go index 593ce83..820b620 100644 --- a/surf.go +++ b/surf.go @@ -5,7 +5,6 @@ import ( "log" "net/http" "net/url" - "time" ) // Surf represents the main Surf client configuration. @@ -122,15 +121,16 @@ func (s *Surf) Request(config *RequestConfig) (*Response, error) { redirects := 0 for { - startTime := time.Now() - performance := newPerformance() + performance := &Performance{ + clientTrace: config.clientTrace, + } resp, err := config.Client.Do(req) if err != nil { return nil, err } - performance.recordResponseTime(startTime) + performance.record() if s.Debug { log.Printf("DEBUG: Received response with status code %d\n", resp.StatusCode) diff --git a/trace.go b/trace.go new file mode 100644 index 0000000..f374e18 --- /dev/null +++ b/trace.go @@ -0,0 +1,62 @@ +package surf + +import ( + "context" + "crypto/tls" + "net/http/httptrace" + "time" +) + +type clientTrace struct { + getConn time.Time + dnsStart time.Time + dnsDone time.Time + connectDone time.Time + tlsHandshakeStart time.Time + tlsHandshakeDone time.Time + gotConn time.Time + gotFirstResponseByte time.Time + endTime time.Time + gotConnInfo httptrace.GotConnInfo +} + +func (t *clientTrace) createContext(ctx context.Context) context.Context { + return httptrace.WithClientTrace( + ctx, + &httptrace.ClientTrace{ + DNSStart: func(_ httptrace.DNSStartInfo) { + t.dnsStart = time.Now() + }, + DNSDone: func(_ httptrace.DNSDoneInfo) { + t.dnsDone = time.Now() + }, + ConnectStart: func(_, _ string) { + if t.dnsDone.IsZero() { + t.dnsDone = time.Now() + } + if t.dnsStart.IsZero() { + t.dnsStart = t.dnsDone + } + }, + ConnectDone: func(net, addr string, err error) { + t.connectDone = time.Now() + }, + GetConn: func(_ string) { + t.getConn = time.Now() + }, + GotConn: func(ci httptrace.GotConnInfo) { + t.gotConn = time.Now() + t.gotConnInfo = ci + }, + GotFirstResponseByte: func() { + t.gotFirstResponseByte = time.Now() + }, + TLSHandshakeStart: func() { + t.tlsHandshakeStart = time.Now() + }, + TLSHandshakeDone: func(_ tls.ConnectionState, _ error) { + t.tlsHandshakeDone = time.Now() + }, + }, + ) +}