client-go: add DNS resolver latency metrics #115357

mfojtik · 2023-01-27T10:10:54Z

What type of PR is this?

/kind feature

What this PR does / why we need it:

DNS failures and resolving latencies today are impossible to track in client-go metrics. If the request timeout is, for example, set to 5s, and DNS resolving takes 4s, then the request might timeout, but the reason why it failed is hidden from admins.
This PR adds a new Prometheus metric rest_client_dns_resolution_duration_seconds that observes the DNS resolver latencies and existing request latency.

It’s not DNS
There’s no way it’s DNS
It was DNS

Special notes for your reviewer:

Does this PR introduce a user-facing change?

NONE

Allow to monitor client-go DNS resolver latencies via `rest_client_dns_resolution_duration_seconds` Prometheus metric

mfojtik · 2023-01-27T10:12:31Z

/cc @deads2k @sttts

mfojtik · 2023-01-27T10:13:54Z

/sig apimachinery

k8s-ci-robot · 2023-01-27T10:13:56Z

@mfojtik: The label(s) sig/apimachinery cannot be applied, because the repository doesn't have them.

In response to this:

/sig apimachinery

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

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

dgrisonnet · 2023-01-27T10:35:48Z

/cc @aojea

aojea · 2023-01-27T10:44:43Z

you don't need to wrap the dialer, and we shouldn't , the http trace already provide dns metrics.

I've already implemented it in client-go, when you use verbosity 9 you can see this metrics

#105156

it seems you just want to hook on that http.trace, but we should avoid adding a new dialer

/cc @liggitt @enj

dgrisonnet · 2023-01-27T10:54:16Z

Thank you for pointing out this effort @aojea, I wasn't aware of it.

One gap I still see is that since the DNS lookup is not taken into account in the current rest client latency metric, it is impossible to detect DNS issues. Even though we would now be able to tell by increasing the verbosity of the logs that DNS latency is high, we don't have an high-level information available at all time that tells us that there is something wrong with the DNS server.

Do you think there could be a way today to record this information in a metric?

mfojtik · 2023-01-27T12:38:38Z

@aojea thanks! I wasn't aware as well that this debugging exists. However, you don't usually run things with verbosity level 9, and it would be nice to see the overall DNS latency measured in case your DNS server is slow or has a problem. I'm open to any solution that does not involve wrapping up dialer :)

tkashem · 2023-01-27T13:21:00Z

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

@@ -938,7 +968,7 @@ func (r *Request) request(ctx context.Context, fn func(*http.Request, *http.Resp

 client := r.c.Client
 if client == nil {
- client = http.DefaultClient
+ client = HttpClientResolverMetricsWrapper(http.DefaultClient)


can we use an interface instead? this will allow more composability, also we can write better unit tests for this

type ClientDecorator interface { Decorate(*http.Client) *http.Client }

we can compose it in Request

type Request struct { ClientDecorator ClientDecorator }

aojea · 2023-01-27T23:55:14Z

Do you think there could be a way today to record this information in a metric?

you just need to pass an httptrace in the context of the request, the same as I did in the example.

The dialer is not used in http2 if there is already a connection, http2 is the default

aojea · 2023-01-31T07:46:49Z

to be more precise, what I'm suggesting is that if you want to get those metrics, you should always pass the httprace I've added as a context and you get the metrics from there, you also have to keep the logging to be printed only with -v9

dgrisonnet · 2023-01-31T09:51:17Z

Thanks for the pointer @aojea :)

cici37 · 2023-01-31T21:06:27Z

/remove-sig api-machinery

aojea · 2023-05-23T11:46:16Z

LGTM once Jordan concern is addressed https://github.com/kubernetes/kubernetes/pull/115357/files#r1161696762

mfojtik · 2023-06-08T14:35:10Z

/retest

mfojtik · 2023-06-08T14:37:13Z

@aojea https://github.com/kubernetes/kubernetes/pull/115357/files#r1202694132 looks addressed :-)

aojea · 2023-06-08T22:22:41Z

@aojea https://github.com/kubernetes/kubernetes/pull/115357/files#r1202694132 looks addressed :-)

but that confirms the race, should we not avoid it?

mfojtik · 2023-06-09T08:34:48Z

@aojea https://github.com/kubernetes/kubernetes/pull/115357/files#r1202694132 looks addressed :-)

but that confirms the race, should we not avoid it?

oh sorry, I misread it. I added locking as separate commit, I hope DNSDone is called also in case of error ;-)

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

Signed-off-by: Vu Dinh <[email protected]>

benluddy · 2023-06-22T20:30:02Z

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

@@ -929,11 +930,35 @@ func (r *Request) newHTTPRequest(ctx context.Context) (*http.Request, error) {
 if err != nil {
 return nil, err
 }
- req = req.WithContext(ctx)
+ req = req.WithContext(httptrace.WithClientTrace(ctx, newDNSMetricsTrace(ctx)))


Since you're touching this, do you want to fold this and the above into a single call to http.NewRequestWithContext? That would avoid a needless shallow copy of every Request.

benluddy · 2023-06-22T20:38:06Z

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

+ // resolverLatency is a Prometheus Histogram metric type partitioned by
+ // "network", and "address" labels. It is used for the rest client DNS resolver latency metrics.


I see that it's consistent with the comment on requestLatency, but isn't this all self-evident? The comment (and now that I'm looking closer, the help text too) has already gone out of sync with the actual set of labels.

benluddy · 2023-06-22T20:38:47Z

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

 req.Header = r.headers
 return req, nil
 }

+// newDNSMetricsTrace returns an HTTP trace that tracks time spend on DNS lookups per network/host.


Suggested change

// newDNSMetricsTrace returns an HTTP trace that tracks time spend on DNS lookups per network/host.

// newDNSMetricsTrace returns an HTTP trace that tracks time spent on DNS lookups per host.

Signed-off-by: Vu Dinh <[email protected]>

dinhxuanvu

@benluddy All fixed.

dinhxuanvu · 2023-06-23T14:44:23Z

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

@@ -929,11 +930,35 @@ func (r *Request) newHTTPRequest(ctx context.Context) (*http.Request, error) {
 if err != nil {
 return nil, err
 }
- req = req.WithContext(ctx)
+ req = req.WithContext(httptrace.WithClientTrace(ctx, newDNSMetricsTrace(ctx)))


dinhxuanvu · 2023-06-23T14:44:36Z

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

+ // resolverLatency is a Prometheus Histogram metric type partitioned by
+ // "network", and "address" labels. It is used for the rest client DNS resolver latency metrics.


dinhxuanvu · 2023-06-23T14:44:44Z

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

 req.Header = r.headers
 return req, nil
 }

+// newDNSMetricsTrace returns an HTTP trace that tracks time spend on DNS lookups per network/host.


dinhxuanvu · 2023-06-23T14:50:17Z

@aojea @deads2k Ready for lgtm and approve :)

dinhxuanvu · 2023-06-23T16:33:26Z

/test pull-kubernetes-e2e-gce

aojea · 2023-06-26T08:02:57Z

/lgtm

k8s-ci-robot · 2023-06-26T08:03:04Z

LGTM label has been added.

Git tree hash: 4b997858766c367a9049ff23d53d8d0263f51d91

aojea · 2023-06-26T22:03:43Z

/label tide/merge-method-squash

deads2k · 2023-06-28T17:41:23Z

/approve

k8s-ci-robot · 2023-06-28T17:41:48Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: deads2k, dgrisonnet, mfojtik

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~staging/src/k8s.io/client-go/OWNERS~~ [deads2k]
~~staging/src/k8s.io/component-base/metrics/OWNERS~~ [dgrisonnet]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

k8s-triage-robot · 2023-06-28T19:58:18Z

The Kubernetes project has merge-blocking tests that are currently too flaky to consistently pass.

This bot retests PRs for certain kubernetes repos according to the following rules:

The PR does have any do-not-merge/* labels
The PR does not have the needs-ok-to-test label
The PR is mergeable (does not have a needs-rebase label)
The PR is approved (has cncf-cla: yes, lgtm, approved labels)
The PR is failing tests required for merge

You can:

Review the full test history for this PR
Prevent this bot from retesting with /lgtm cancel or /hold
Help make our tests less flaky by following our Flaky Tests Guide

/retest

* 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 <[email protected]> * Fix a mismatched ctx on the request Signed-off-by: Vu Dinh <[email protected]> * Clean up request code and fix comments Signed-off-by: Vu Dinh <[email protected]> --------- Signed-off-by: Vu Dinh <[email protected]> Co-authored-by: Vu Dinh <[email protected]>

k8s-ci-robot requested review from deads2k and jayunit100 January 27, 2023 10:12

k8s-ci-robot requested a review from sttts January 27, 2023 10:12

dgrisonnet reviewed Jan 27, 2023

View reviewed changes

staging/src/k8s.io/client-go/rest/request.go Outdated Show resolved Hide resolved

k8s-ci-robot requested a review from aojea January 27, 2023 10:35

k8s-ci-robot requested review from enj and liggitt January 27, 2023 10:44

tkashem reviewed Jan 27, 2023

View reviewed changes

client-go: add locking to DNS latency metrics

c836f4a

mfojtik force-pushed the resolver-client-metrics branch from 6769f47 to c836f4a Compare June 9, 2023 08:36

aojea reviewed Jun 9, 2023

View reviewed changes

staging/src/k8s.io/client-go/rest/request.go Show resolved Hide resolved

dinhxuanvu mentioned this pull request Jun 12, 2023

add event interval from rest client metric broken down by source openshift/origin#27976

Closed

dinhxuanvu added 2 commits June 22, 2023 03:04

client-go: add locking for whole DNSStart and DNSDone

c5fac10

Signed-off-by: Vu Dinh <[email protected]>

Fix a mismatched ctx on the request

9be0263

Signed-off-by: Vu Dinh <[email protected]>

benluddy reviewed Jun 22, 2023

View reviewed changes

Clean up request code and fix comments

108278c

Signed-off-by: Vu Dinh <[email protected]>

dinhxuanvu reviewed Jun 23, 2023

View reviewed changes

k8s-ci-robot assigned aojea Jun 26, 2023

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Jun 26, 2023

k8s-ci-robot added the tide/merge-method-squash Denotes a PR that should be squashed by tide when it merges. label Jun 26, 2023

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Jun 28, 2023

k8s-ci-robot merged commit 1c7e87c into kubernetes:master Jun 28, 2023
12 checks passed

k8s-ci-robot added this to the v1.28 milestone Jun 28, 2023

		// resolverLatency is a Prometheus Histogram metric type partitioned by
		// "network", and "address" labels. It is used for the rest client DNS resolver latency metrics.

	// newDNSMetricsTrace returns an HTTP trace that tracks time spend on DNS lookups per network/host.
	// newDNSMetricsTrace returns an HTTP trace that tracks time spent on DNS lookups per host.

client-go: add DNS resolver latency metrics #115357

client-go: add DNS resolver latency metrics #115357

Conversation

mfojtik commented Jan 27, 2023 • edited

What type of PR is this?

What this PR does / why we need it:

Special notes for your reviewer:

Does this PR introduce a user-facing change?

mfojtik commented Jan 27, 2023

mfojtik commented Jan 27, 2023

k8s-ci-robot commented Jan 27, 2023

dgrisonnet commented Jan 27, 2023

aojea commented Jan 27, 2023

dgrisonnet commented Jan 27, 2023

mfojtik commented Jan 27, 2023

Choose a reason for hiding this comment

aojea commented Jan 27, 2023

aojea commented Jan 31, 2023

dgrisonnet commented Jan 31, 2023

cici37 commented Jan 31, 2023

aojea commented May 23, 2023

mfojtik commented Jun 8, 2023

mfojtik commented Jun 8, 2023

aojea commented Jun 8, 2023

mfojtik commented Jun 9, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dinhxuanvu left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dinhxuanvu commented Jun 23, 2023

dinhxuanvu commented Jun 23, 2023

aojea commented Jun 26, 2023

k8s-ci-robot commented Jun 26, 2023

aojea commented Jun 26, 2023

deads2k commented Jun 28, 2023

k8s-ci-robot commented Jun 28, 2023

k8s-triage-robot commented Jun 28, 2023

mfojtik commented Jan 27, 2023 •

edited