From fad094cb70c26f962c49d615b1f48326aa25181d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pawe=C5=82=20Banaszewski?= Date: Mon, 7 Nov 2022 14:33:40 +0000 Subject: [PATCH 1/2] Added Verb and Resource to request trace attributes --- .../pkg/endpoints/handlers/helpers.go | 37 +++++++++++++++++++ .../pkg/endpoints/handlers/helpers_test.go | 3 +- .../pkg/endpoints/handlers/trace_util.go | 8 ++-- 3 files changed, 44 insertions(+), 4 deletions(-) diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go index a25e76db627..fe42370602d 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go @@ -21,6 +21,7 @@ import ( utilnet "k8s.io/apimachinery/pkg/util/net" "k8s.io/apiserver/pkg/audit" + apirequest "k8s.io/apiserver/pkg/endpoints/request" ) const ( @@ -88,3 +89,39 @@ func (lazy *lazyAuditID) String() string { return "unknown" } + +// lazyVerb implements String() string and it will +// lazily get Verb from request info based on request context +type lazyVerb struct { + req *http.Request +} + +func (lazy *lazyVerb) String() string { + if lazy.req != nil { + ctx := lazy.req.Context() + requestInfo, ok := apirequest.RequestInfoFrom(ctx) + if ok { + return requestInfo.Verb + } + } + + return "unknown" +} + +// lazyVerb implements String() string and it will +// lazily get Resource from request info based on request context +type lazyResource struct { + req *http.Request +} + +func (lazy *lazyResource) String() string { + if lazy.req != nil { + ctx := lazy.req.Context() + requestInfo, ok := apirequest.RequestInfoFrom(ctx) + if ok { + return requestInfo.Resource + } + } + + return "unknown" +} diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go index 3f7e3dc106e..e70480d9d04 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go @@ -18,9 +18,10 @@ package handlers import ( "fmt" - "github.com/stretchr/testify/assert" "net/http" "testing" + + "github.com/stretchr/testify/assert" ) func TestLazyTruncatedUserAgent(t *testing.T) { diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/trace_util.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/trace_util.go index c17401eec70..32790d1419f 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/trace_util.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/trace_util.go @@ -24,11 +24,13 @@ import ( func traceFields(req *http.Request) []attribute.KeyValue { return []attribute.KeyValue{ - attribute.String("url", req.URL.Path), - attribute.Stringer("user-agent", &lazyTruncatedUserAgent{req: req}), + attribute.Stringer("accept", &lazyAccept{req: req}), attribute.Stringer("audit-id", &lazyAuditID{req: req}), attribute.Stringer("client", &lazyClientIP{req: req}), - attribute.Stringer("accept", &lazyAccept{req: req}), attribute.String("protocol", req.Proto), + attribute.Stringer("resource", &lazyResource{req: req}), + attribute.String("url", req.URL.Path), + attribute.Stringer("user-agent", &lazyTruncatedUserAgent{req: req}), + attribute.Stringer("verb", &lazyVerb{req: req}), } } From b31339231314ae8a72481cfda45539e35097450a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pawe=C5=82=20Banaszewski?= Date: Mon, 7 Nov 2022 17:13:26 +0000 Subject: [PATCH 2/2] Added simple tests and changed lazyVerb String method to the same as httplog uses --- .../pkg/endpoints/handlers/helpers.go | 18 ++++++-------- .../pkg/endpoints/handlers/helpers_test.go | 24 +++++++++++++++++++ .../pkg/endpoints/metrics/metrics.go | 14 +++++++++++ .../apiserver/pkg/server/httplog/httplog.go | 11 +-------- 4 files changed, 46 insertions(+), 21 deletions(-) diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go index fe42370602d..81e34a717da 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers.go @@ -21,6 +21,7 @@ import ( utilnet "k8s.io/apimachinery/pkg/util/net" "k8s.io/apiserver/pkg/audit" + "k8s.io/apiserver/pkg/endpoints/metrics" apirequest "k8s.io/apiserver/pkg/endpoints/request" ) @@ -91,25 +92,20 @@ func (lazy *lazyAuditID) String() string { } // lazyVerb implements String() string and it will -// lazily get Verb from request info based on request context +// lazily get normalized Verb type lazyVerb struct { req *http.Request } func (lazy *lazyVerb) String() string { - if lazy.req != nil { - ctx := lazy.req.Context() - requestInfo, ok := apirequest.RequestInfoFrom(ctx) - if ok { - return requestInfo.Verb - } + if lazy.req == nil { + return "unknown" } - - return "unknown" + return metrics.NormalizedVerb(lazy.req) } -// lazyVerb implements String() string and it will -// lazily get Resource from request info based on request context +// lazyResource implements String() string and it will +// lazily get Resource from request info type lazyResource struct { req *http.Request } diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go index e70480d9d04..4666524bcd1 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/helpers_test.go @@ -17,11 +17,14 @@ limitations under the License. package handlers import ( + "context" "fmt" "net/http" + "net/url" "testing" "github.com/stretchr/testify/assert" + "k8s.io/apiserver/pkg/endpoints/request" ) func TestLazyTruncatedUserAgent(t *testing.T) { @@ -72,3 +75,24 @@ func TestLazyAccept(t *testing.T) { acceptWithoutReq := &lazyAccept{} assert.Equal(t, "unknown", fmt.Sprintf("%v", acceptWithoutReq)) } + +func TestLazyVerb(t *testing.T) { + assert.Equal(t, "unknown", fmt.Sprintf("%v", &lazyVerb{})) + + u, _ := url.Parse("?watch=true") + req := &http.Request{Method: "GET", URL: u} + verbWithReq := &lazyVerb{req: req} + assert.Equal(t, "WATCH", fmt.Sprintf("%v", verbWithReq)) +} + +func TestLazyResource(t *testing.T) { + assert.Equal(t, "unknown", fmt.Sprintf("%v", &lazyResource{})) + + resourceWithEmptyReq := &lazyResource{&http.Request{}} + assert.Equal(t, "unknown", fmt.Sprintf("%v", resourceWithEmptyReq)) + + req := &http.Request{} + ctx := request.WithRequestInfo(context.TODO(), &request.RequestInfo{Resource: "resource"}) + resourceWithReq := &lazyResource{req: req.WithContext(ctx)} + assert.Equal(t, "resource", fmt.Sprintf("%v", resourceWithReq)) +} diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go b/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go index fa6a2f073a9..1797f16d2fe 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/metrics/metrics.go @@ -565,6 +565,20 @@ func InstrumentHandlerFunc(verb, group, version, resource, subresource, scope, c } } +// NormalizedVerb returns normalized verb +func NormalizedVerb(req *http.Request) string { + verb := req.Method + if requestInfo, ok := request.RequestInfoFrom(req.Context()); ok { + // If we can find a requestInfo, we can get a scope, and then + // we can convert GETs to LISTs when needed. + scope := CleanScope(requestInfo) + verb = CanonicalVerb(strings.ToUpper(verb), scope) + } + + // mark APPLY requests and WATCH requests correctly. + return CleanVerb(verb, req) +} + // CleanScope returns the scope of the request. func CleanScope(requestInfo *request.RequestInfo) string { if requestInfo.Name != "" || requestInfo.Verb == "create" { diff --git a/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go b/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go index a6120440ca6..4d6248f834f 100644 --- a/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go +++ b/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go @@ -243,16 +243,7 @@ func SetStacktracePredicate(ctx context.Context, pred StacktracePred) { func (rl *respLogger) Log() { latency := time.Since(rl.startTime) auditID := audit.GetAuditIDTruncated(rl.req.Context()) - - verb := rl.req.Method - if requestInfo, ok := request.RequestInfoFrom(rl.req.Context()); ok { - // If we can find a requestInfo, we can get a scope, and then - // we can convert GETs to LISTs when needed. - scope := metrics.CleanScope(requestInfo) - verb = metrics.CanonicalVerb(strings.ToUpper(verb), scope) - } - // mark APPLY requests and WATCH requests correctly. - verb = metrics.CleanVerb(verb, rl.req) + verb := metrics.NormalizedVerb(rl.req) keysAndValues := []interface{}{ "verb", verb,