diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication_test.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication_test.go index 865bab11cc5..639dc980f81 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication_test.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication_test.go @@ -704,3 +704,35 @@ func TestUnauthenticatedHTTP2ClientConnectionClose(t *testing.T) { }) } } + +func TestAuthenticationLatencyTracked(t *testing.T) { + successHandlerCalled := false + handler := WithAuthentication( + http.HandlerFunc(func(_ http.ResponseWriter, req *http.Request) { + // latency annotations should be added by the time the success handler is called + annotations := genericapirequest.AuditAnnotationsFromLatencyTrackers(req.Context()) + if annotations["apiserver.latency.k8s.io/authentication"] == "" { + t.Errorf("missing authentication latency annotation: %v", annotations) + } + successHandlerCalled = true + }), + authenticator.RequestFunc(func(req *http.Request) (*authenticator.Response, bool, error) { + return &authenticator.Response{User: &user.DefaultInfo{Name: "user"}}, true, nil + }), + http.HandlerFunc(func(_ http.ResponseWriter, _ *http.Request) { + t.Error("unexpected call to error handler") + }), + nil, + nil, + ) + handler = WithLatencyTrackers(handler) + handler = WithRequestInfo(handler, &fakeRequestResolver{}) + req, err := http.NewRequest(http.MethodGet, "/", nil) + if err != nil { + t.Fatal(err) + } + handler.ServeHTTP(httptest.NewRecorder(), req) + if !successHandlerCalled { + t.Fatal("no call to success handler") + } +} diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go index 29acc428688..6c6c94ba718 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authorization.go @@ -71,9 +71,9 @@ func withAuthorization(handler http.Handler, a authorizer.Authorizer, s runtime. authorized, reason, err := a.Authorize(ctx, attributes) authorizationFinish := time.Now() + request.TrackAuthorizationLatency(ctx, authorizationFinish.Sub(authorizationStart)) defer func() { metrics(ctx, authorized, err, authorizationStart, authorizationFinish) - request.TrackAuthorizationLatency(ctx, authorizationFinish.Sub(authorizationStart)) }() // an authorizer like RBAC could encounter evaluation errors and still allow the request, so authorizer decision is checked before error here. diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go index e1c89da78dd..62eb4f948e8 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/filters/webhook_duration.go @@ -71,9 +71,7 @@ func (wt *writeLatencyTracker) Unwrap() http.ResponseWriter { func (wt *writeLatencyTracker) Write(bs []byte) (int, error) { startedAt := time.Now() - defer func() { - request.TrackResponseWriteLatency(wt.ctx, time.Since(startedAt)) - }() - - return wt.ResponseWriter.Write(bs) + n, err := wt.ResponseWriter.Write(bs) + request.TrackResponseWriteLatency(wt.ctx, time.Since(startedAt)) + return n, err }