client-go: add DNS resolver latency metrics (#115357)

* client-go: add DNS resolver latency metrics

* client-go: add locking to DNS latency metrics

* client-go: add locking for whole DNSStart and DNSDone

Signed-off-by: Vu Dinh <vudinh@outlook.com>

* Fix a mismatched ctx on the request

Signed-off-by: Vu Dinh <vudinh@outlook.com>

* Clean up request code and fix comments

Signed-off-by: Vu Dinh <vudinh@outlook.com>

---------

Signed-off-by: Vu Dinh <vudinh@outlook.com>
Co-authored-by: Vu Dinh <vudinh@outlook.com>

staging/src/k8s.io/client-go/rest/request.go

@@ -24,6 +24,7 @@ import (
 	"io"
 	"mime"
 	"net/http"
+	"net/http/httptrace"
 	"net/url"
 	"os"
 	"path"
@@ -925,15 +926,38 @@ func (r *Request) newHTTPRequest(ctx context.Context) (*http.Request, error) {
 	}
 
 	url := r.URL().String()
-	req, err := http.NewRequest(r.verb, url, body)
+	req, err := http.NewRequestWithContext(httptrace.WithClientTrace(ctx, newDNSMetricsTrace(ctx)), r.verb, url, body)
 	if err != nil {
 		return nil, err
 	}
-	req = req.WithContext(ctx)
 	req.Header = r.headers
 	return req, nil
 }
 
+// newDNSMetricsTrace returns an HTTP trace that tracks time spent on DNS lookups per host.
+// This metric is available in client as "rest_client_dns_resolution_duration_seconds".
+func newDNSMetricsTrace(ctx context.Context) *httptrace.ClientTrace {
+	type dnsMetric struct {
+		start time.Time
+		host  string
+		sync.Mutex
+	}
+	dns := &dnsMetric{}
+	return &httptrace.ClientTrace{
+		DNSStart: func(info httptrace.DNSStartInfo) {
+			dns.Lock()
+			defer dns.Unlock()
+			dns.start = time.Now()
+			dns.host = info.Host
+		},
+		DNSDone: func(info httptrace.DNSDoneInfo) {
+			dns.Lock()
+			defer dns.Unlock()
+			metrics.ResolverLatency.Observe(ctx, dns.host, time.Since(dns.start))
+		},
+	}
+}
+
 // request connects to the server and invokes the provided function when a server response is
 // received. It handles retry behavior and up front validation of requests. It will invoke
 // fn at most once. It will return an error if a problem occurred prior to connecting to the

staging/src/k8s.io/client-go/tools/metrics/metrics.go

@@ -42,6 +42,10 @@ type LatencyMetric interface {
 	Observe(ctx context.Context, verb string, u url.URL, latency time.Duration)
 }
 
+type ResolverLatencyMetric interface {
+	Observe(ctx context.Context, host string, latency time.Duration)
+}
+
 // SizeMetric observes client response size partitioned by verb and host.
 type SizeMetric interface {
 	Observe(ctx context.Context, verb string, host string, size float64)
@@ -82,6 +86,8 @@ var (
 	ClientCertRotationAge DurationMetric = noopDuration{}
 	// RequestLatency is the latency metric that rest clients will update.
 	RequestLatency LatencyMetric = noopLatency{}
+	// ResolverLatency is the latency metric that DNS resolver will update
+	ResolverLatency ResolverLatencyMetric = noopResolverLatency{}
 	// RequestSize is the request size metric that rest clients will update.
 	RequestSize SizeMetric = noopSize{}
 	// ResponseSize is the response size metric that rest clients will update.
@@ -109,6 +115,7 @@ type RegisterOpts struct {
 	ClientCertExpiry      ExpiryMetric
 	ClientCertRotationAge DurationMetric
 	RequestLatency        LatencyMetric
+	ResolverLatency       ResolverLatencyMetric
 	RequestSize           SizeMetric
 	ResponseSize          SizeMetric
 	RateLimiterLatency    LatencyMetric
@@ -132,6 +139,9 @@ func Register(opts RegisterOpts) {
 		if opts.RequestLatency != nil {
 			RequestLatency = opts.RequestLatency
 		}
+		if opts.ResolverLatency != nil {
+			ResolverLatency = opts.ResolverLatency
+		}
 		if opts.RequestSize != nil {
 			RequestSize = opts.RequestSize
 		}
@@ -171,6 +181,11 @@ type noopLatency struct{}
 
 func (noopLatency) Observe(context.Context, string, url.URL, time.Duration) {}
 
+type noopResolverLatency struct{}
+
+func (n noopResolverLatency) Observe(ctx context.Context, host string, latency time.Duration) {
+}
+
 type noopSize struct{}
 
 func (noopSize) Observe(context.Context, string, string, float64) {}

staging/src/k8s.io/component-base/metrics/prometheus/restclient/metrics.go

@@ -41,6 +41,18 @@ var (
 		[]string{"verb", "host"},
 	)
 
+	// resolverLatency is a Prometheus Histogram metric type partitioned by
+	// "host" labels. It is used for the rest client DNS resolver latency metrics.
+	resolverLatency = k8smetrics.NewHistogramVec(
+		&k8smetrics.HistogramOpts{
+			Name:           "rest_client_dns_resolution_duration_seconds",
+			Help:           "DNS resolver latency in seconds. Broken down by host.",
+			StabilityLevel: k8smetrics.ALPHA,
+			Buckets:        []float64{0.005, 0.025, 0.1, 0.25, 0.5, 1.0, 2.0, 4.0, 8.0, 15.0, 30.0},
+		},
+		[]string{"host"},
+	)
+
 	requestSize = k8smetrics.NewHistogramVec(
 		&k8smetrics.HistogramOpts{
 			Name:           "rest_client_request_size_bytes",
@@ -189,6 +201,7 @@ func init() {
 		ClientCertExpiry:      execPluginCertTTLAdapter,
 		ClientCertRotationAge: &rotationAdapter{m: execPluginCertRotation},
 		RequestLatency:        &latencyAdapter{m: requestLatency},
+		ResolverLatency:       &resolverLatencyAdapter{m: resolverLatency},
 		RequestSize:           &sizeAdapter{m: requestSize},
 		ResponseSize:          &sizeAdapter{m: responseSize},
 		RateLimiterLatency:    &latencyAdapter{m: rateLimiterLatency},
@@ -208,6 +221,14 @@ func (l *latencyAdapter) Observe(ctx context.Context, verb string, u url.URL, la
 	l.m.WithContext(ctx).WithLabelValues(verb, u.Host).Observe(latency.Seconds())
 }
 
+type resolverLatencyAdapter struct {
+	m *k8smetrics.HistogramVec
+}
+
+func (l *resolverLatencyAdapter) Observe(ctx context.Context, host string, latency time.Duration) {
+	l.m.WithContext(ctx).WithLabelValues(host).Observe(latency.Seconds())
+}
+
 type sizeAdapter struct {
 	m *k8smetrics.HistogramVec
 }