Enable nested tracing, add request filter chain tracing incl. authn/authz tracing

Author: jpbetz

pkg/scheduler/core/BUILD

@@ -23,6 +23,7 @@ go_library(
         "//staging/src/k8s.io/apimachinery/pkg/apis/meta/v1:go_default_library",
         "//staging/src/k8s.io/apimachinery/pkg/util/net:go_default_library",
         "//staging/src/k8s.io/apimachinery/pkg/util/sets:go_default_library",
+        "//staging/src/k8s.io/apiserver/pkg/endpoints/request:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/util/feature:go_default_library",
         "//staging/src/k8s.io/client-go/listers/core/v1:go_default_library",
         "//staging/src/k8s.io/client-go/rest:go_default_library",

pkg/scheduler/core/generic_scheduler.go

@@ -30,6 +30,7 @@ import (
 
 	v1 "k8s.io/api/core/v1"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
+	genericapirequest "k8s.io/apiserver/pkg/endpoints/request"
 	utilfeature "k8s.io/apiserver/pkg/util/feature"
 	corelisters "k8s.io/client-go/listers/core/v1"
 	extenderv1 "k8s.io/kube-scheduler/extender/v1"
@@ -136,7 +137,7 @@ func (g *genericScheduler) snapshot() error {
 // If it succeeds, it will return the name of the node.
 // If it fails, it will return a FitError error with reasons.
 func (g *genericScheduler) Schedule(ctx context.Context, prof *profile.Profile, state *framework.CycleState, pod *v1.Pod) (result ScheduleResult, err error) {
-	trace := utiltrace.New("Scheduling", utiltrace.Field{Key: "namespace", Value: pod.Namespace}, utiltrace.Field{Key: "name", Value: pod.Name})
+	ctx, trace := genericapirequest.WithTrace(ctx, "Scheduling", utiltrace.Field{Key: "namespace", Value: pod.Namespace}, utiltrace.Field{Key: "name", Value: pod.Name})
 	defer trace.LogIfLong(100 * time.Millisecond)
 
 	if err := podPassesBasicChecks(pod, g.pvcLister); err != nil {

staging/src/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion/BUILD

@@ -24,6 +24,7 @@ go_library(
         "//staging/src/k8s.io/apimachinery/pkg/types:go_default_library",
         "//staging/src/k8s.io/apimachinery/pkg/util/uuid:go_default_library",
         "//staging/src/k8s.io/apimachinery/pkg/util/validation/field:go_default_library",
+        "//staging/src/k8s.io/apiserver/pkg/endpoints/request:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/util/webhook:go_default_library",
         "//staging/src/k8s.io/client-go/kubernetes/scheme:go_default_library",
         "//staging/src/k8s.io/client-go/rest:go_default_library",

staging/src/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion/webhook_converter.go

@@ -34,6 +34,7 @@ import (
 	"k8s.io/apimachinery/pkg/types"
 	"k8s.io/apimachinery/pkg/util/uuid"
 	"k8s.io/apimachinery/pkg/util/validation/field"
+	genericapirequest "k8s.io/apiserver/pkg/endpoints/request"
 	"k8s.io/apiserver/pkg/util/webhook"
 	"k8s.io/client-go/rest"
 	utiltrace "k8s.io/utils/trace"
@@ -259,7 +260,7 @@ func (c *webhookConverter) Convert(in runtime.Object, toGV schema.GroupVersion)
 		return out, nil
 	}
 
-	trace := utiltrace.New("Call conversion webhook",
+	ctx, trace := genericapirequest.WithTrace(context.TODO(), "Call conversion webhook",
 		utiltrace.Field{"custom-resource-definition", c.name},
 		utiltrace.Field{"desired-api-version", desiredAPIVersion},
 		utiltrace.Field{"object-count", objCount},
@@ -269,8 +270,6 @@ func (c *webhookConverter) Convert(in runtime.Object, toGV schema.GroupVersion)
 	// the conversion request on the apiserver side (~4ms per object).
 	defer trace.LogIfLong(time.Duration(50+8*objCount) * time.Millisecond)
 
-	// TODO: Figure out if adding one second timeout make sense here.
-	ctx := context.TODO()
 	r := c.restClient.Post().Body(request).Do(ctx)
 	if err := r.Into(response); err != nil {
 		// TODO: Return a webhook specific error to be able to convert it to meta.Status

staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/BUILD

@@ -29,6 +29,7 @@ go_library(
         "//staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/generic:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/request:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/apis/audit:go_default_library",
+        "//staging/src/k8s.io/apiserver/pkg/endpoints/request:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/util/webhook:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/warning:go_default_library",
         "//vendor/github.com/evanphx/json-patch:go_default_library",

staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go

@@ -42,6 +42,7 @@ import (
 	"k8s.io/apiserver/pkg/admission/plugin/webhook/generic"
 	webhookrequest "k8s.io/apiserver/pkg/admission/plugin/webhook/request"
 	auditinternal "k8s.io/apiserver/pkg/apis/audit"
+	genericapirequest "k8s.io/apiserver/pkg/endpoints/request"
 	webhookutil "k8s.io/apiserver/pkg/util/webhook"
 	"k8s.io/apiserver/pkg/warning"
 	utiltrace "k8s.io/utils/trace"
@@ -221,7 +222,7 @@ func (a *mutatingDispatcher) callAttrMutatingHook(ctx context.Context, h *admiss
 	if err != nil {
 		return false, &webhookutil.ErrCallingWebhook{WebhookName: h.Name, Reason: err}
 	}
-	trace := utiltrace.New("Call mutating webhook",
+	ctx, trace := genericapirequest.WithTrace(ctx, "Call mutating webhook",
 		utiltrace.Field{"configuration", configurationName},
 		utiltrace.Field{"webhook", h.Name},
 		utiltrace.Field{"resource", attr.GetResource()},

staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/BUILD

@@ -22,6 +22,7 @@ go_library(
         "//staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/errors:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/generic:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/request:go_default_library",
+        "//staging/src/k8s.io/apiserver/pkg/endpoints/request:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/util/webhook:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/warning:go_default_library",
         "//vendor/k8s.io/klog/v2:go_default_library",

staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go

@@ -32,6 +32,7 @@ import (
 	webhookerrors "k8s.io/apiserver/pkg/admission/plugin/webhook/errors"
 	"k8s.io/apiserver/pkg/admission/plugin/webhook/generic"
 	webhookrequest "k8s.io/apiserver/pkg/admission/plugin/webhook/request"
+	genericapirequest "k8s.io/apiserver/pkg/endpoints/request"
 	webhookutil "k8s.io/apiserver/pkg/util/webhook"
 	"k8s.io/apiserver/pkg/warning"
 	"k8s.io/klog/v2"
@@ -181,7 +182,7 @@ func (d *validatingDispatcher) callHook(ctx context.Context, h *v1.ValidatingWeb
 	if err != nil {
 		return &webhookutil.ErrCallingWebhook{WebhookName: h.Name, Reason: err}
 	}
-	trace := utiltrace.New("Call validating webhook",
+	ctx, trace := genericapirequest.WithTrace(ctx, "Call validating webhook",
 		utiltrace.Field{"configuration", invocation.Webhook.GetConfigurationName()},
 		utiltrace.Field{"webhook", h.Name},
 		utiltrace.Field{"resource", attr.GetResource()},

staging/src/k8s.io/apiserver/pkg/endpoints/BUILD

@@ -112,6 +112,7 @@ filegroup(
         "//staging/src/k8s.io/apiserver/pkg/endpoints/discovery:all-srcs",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/filters:all-srcs",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/handlers:all-srcs",
+        "//staging/src/k8s.io/apiserver/pkg/endpoints/internal:all-srcs",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/metrics:all-srcs",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/openapi:all-srcs",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/request:all-srcs",

staging/src/k8s.io/apiserver/pkg/endpoints/filters/BUILD

@@ -55,6 +55,7 @@ go_library(
         "impersonation.go",
         "metrics.go",
         "requestinfo.go",
+        "trace.go",
         "warning.go",
     ],
     importmap = "k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/endpoints/filters",
@@ -76,12 +77,14 @@ go_library(
         "//staging/src/k8s.io/apiserver/pkg/authentication/user:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/authorization/authorizer:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/handlers/responsewriters:go_default_library",
+        "//staging/src/k8s.io/apiserver/pkg/endpoints/internal:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/endpoints/request:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/server/httplog:go_default_library",
         "//staging/src/k8s.io/apiserver/pkg/warning:go_default_library",
         "//staging/src/k8s.io/component-base/metrics:go_default_library",
         "//staging/src/k8s.io/component-base/metrics/legacyregistry:go_default_library",
         "//vendor/k8s.io/klog/v2:go_default_library",
+        "//vendor/k8s.io/utils/trace:go_default_library",
     ],
 )