diff --git a/pkg/scheduler/core/generic_scheduler.go b/pkg/scheduler/core/generic_scheduler.go index ac261671857..b7da5e31f96 100644 --- a/pkg/scheduler/core/generic_scheduler.go +++ b/pkg/scheduler/core/generic_scheduler.go @@ -187,7 +187,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(pod *v1.Pod, nodeLister algorithm.NodeLister, pluginContext *framework.PluginContext) (result ScheduleResult, err error) { - trace := utiltrace.New(fmt.Sprintf("Scheduling %s/%s", pod.Namespace, pod.Name)) + trace := utiltrace.New("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 { diff --git a/staging/src/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion/webhook_converter.go b/staging/src/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion/webhook_converter.go index 3beb8329eb4..602659b0093 100644 --- a/staging/src/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion/webhook_converter.go +++ b/staging/src/k8s.io/apiextensions-apiserver/pkg/apiserver/conversion/webhook_converter.go @@ -182,9 +182,11 @@ func (c *webhookConverter) Convert(in runtime.Object, toGV schema.GroupVersion) return out, nil } - trace := utiltrace.New(fmt.Sprintf( - "Call conversion webhook: custom resource definition: %s, desired API version: %s, object count: %d, UID: %v", - c.name, request.Request.DesiredAPIVersion, objCount, request.Request.UID)) + trace := utiltrace.New("Call conversion webhook", + utiltrace.Field{"custom-resource-definition", c.name}, + utiltrace.Field{"desired-api-version", request.Request.DesiredAPIVersion}, + utiltrace.Field{"object-count", objCount}, + utiltrace.Field{"UID", request.Request.UID}) // Only log conversion webhook traces that exceed a 8ms per object limit plus a 50ms request overhead allowance. // The per object limit uses the SLO for conversion webhooks (~4ms per object) plus time to serialize/deserialize // the conversion request on the apiserver side (~4ms per object). diff --git a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go index 9305751d31c..cf0e76a60c5 100644 --- a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go +++ b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/mutating/dispatcher.go @@ -173,10 +173,14 @@ func (a *mutatingDispatcher) callAttrMutatingHook(ctx context.Context, h *v1beta if err != nil { return false, &webhookutil.ErrCallingWebhook{WebhookName: h.Name, Reason: err} } - trace := utiltrace.New(fmt.Sprintf("Call mutating webhook: configuration: %s, webhook: %s, resource: %v, subResource: %s, operation: %v, UID: %v", - invocation.Webhook.GetConfigurationName(), h.Name, request.Request.Resource, request.Request.SubResource, request.Request.Operation, request.Request.UID)) + trace := utiltrace.New("Call mutating webhook", + utiltrace.Field{"configuration", invocation.Webhook.GetConfigurationName()}, + utiltrace.Field{"webhook", h.Name}, + utiltrace.Field{"resource", attr.GetResource()}, + utiltrace.Field{"subresource", attr.GetSubresource()}, + utiltrace.Field{"operation", attr.GetOperation()}, + utiltrace.Field{"UID", uid}) defer trace.LogIfLong(500 * time.Millisecond) - response := &admissionv1beta1.AdmissionReview{} r := client.Post().Context(ctx).Body(request) if h.TimeoutSeconds != nil { r = r.Timeout(time.Duration(*h.TimeoutSeconds) * time.Second) diff --git a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go index 57a6a2a03f8..6525524f5b0 100644 --- a/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go +++ b/staging/src/k8s.io/apiserver/pkg/admission/plugin/webhook/validating/dispatcher.go @@ -154,10 +154,14 @@ func (d *validatingDispatcher) callHook(ctx context.Context, h *v1beta1.Validati if err != nil { return &webhookutil.ErrCallingWebhook{WebhookName: h.Name, Reason: err} } - trace := utiltrace.New(fmt.Sprintf("Call validating webhook: configuration: %s, webhook: %s, resource: %v, subResource: %s, operation: %v, UID: %v", - invocation.Webhook.GetConfigurationName(), h.Name, request.Request.Resource, request.Request.SubResource, request.Request.Operation, request.Request.UID)) + trace := utiltrace.New("Call validating webhook", + utiltrace.Field{"configuration", invocation.Webhook.GetConfigurationName()}, + utiltrace.Field{"webhook", h.Name}, + utiltrace.Field{"resource", attr.GetResource()}, + utiltrace.Field{"subresource", attr.GetSubresource()}, + utiltrace.Field{"operation", attr.GetOperation()}, + utiltrace.Field{"UID", uid}) defer trace.LogIfLong(500 * time.Millisecond) - response := &admissionv1beta1.AdmissionReview{} r := client.Post().Context(ctx).Body(request) if h.TimeoutSeconds != nil { r = r.Timeout(time.Duration(*h.TimeoutSeconds) * time.Second) diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/create.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/create.go index d4a31b7e7e2..ae3fbcae0f7 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/create.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/create.go @@ -46,7 +46,7 @@ import ( func createHandler(r rest.NamedCreater, scope *RequestScope, admit admission.Interface, includeName bool) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { // For performance tracking purposes. - trace := utiltrace.New("Create " + req.URL.Path) + trace := utiltrace.New("Create", utiltrace.Field{"url", req.URL.Path}) defer trace.LogIfLong(500 * time.Millisecond) if isDryRun(req.URL) && !utilfeature.DefaultFeatureGate.Enabled(features.DryRun) { diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/delete.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/delete.go index 2ac2cc3f131..08ba77650f3 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/delete.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/delete.go @@ -43,7 +43,7 @@ import ( func DeleteResource(r rest.GracefulDeleter, allowsOptions bool, scope *RequestScope, admit admission.Interface) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { // For performance tracking purposes. - trace := utiltrace.New("Delete " + req.URL.Path) + trace := utiltrace.New("Delete", utiltrace.Field{"url", req.URL.Path}) defer trace.LogIfLong(500 * time.Millisecond) if isDryRun(req.URL) && !utilfeature.DefaultFeatureGate.Enabled(features.DryRun) { @@ -160,7 +160,7 @@ func DeleteResource(r rest.GracefulDeleter, allowsOptions bool, scope *RequestSc // DeleteCollection returns a function that will handle a collection deletion func DeleteCollection(r rest.CollectionDeleter, checkBody bool, scope *RequestScope, admit admission.Interface) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { - trace := utiltrace.New("Delete " + req.URL.Path) + trace := utiltrace.New("Delete", utiltrace.Field{"url", req.URL.Path}) defer trace.LogIfLong(500 * time.Millisecond) if isDryRun(req.URL) && !utilfeature.DefaultFeatureGate.Enabled(features.DryRun) { diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/get.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/get.go index af7ae1d54fd..425ba323a24 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/get.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/get.go @@ -48,7 +48,7 @@ type getterFunc func(ctx context.Context, name string, req *http.Request, trace // passed-in getterFunc to perform the actual get. func getResourceHandler(scope *RequestScope, getter getterFunc) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { - trace := utiltrace.New("Get " + req.URL.Path) + trace := utiltrace.New("Get", utiltrace.Field{"url", req.URL.Path}) defer trace.LogIfLong(500 * time.Millisecond) namespace, name, err := scope.Namer.Name(req) @@ -165,7 +165,7 @@ func getRequestOptions(req *http.Request, scope *RequestScope, into runtime.Obje func ListResource(r rest.Lister, rw rest.Watcher, scope *RequestScope, forceWatch bool, minRequestTimeout time.Duration) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { // For performance tracking purposes. - trace := utiltrace.New("List " + req.URL.Path) + trace := utiltrace.New("List", utiltrace.Field{"url", req.URL.Path}) namespace, err := scope.Namer.Namespace(req) if err != nil { @@ -273,6 +273,6 @@ func ListResource(r rest.Lister, rw rest.Watcher, scope *RequestScope, forceWatc trace.Step("Listing from storage done") transformResponseObject(ctx, scope, trace, req, w, http.StatusOK, outputMediaType, result) - trace.Step(fmt.Sprintf("Writing http response done (%d items)", meta.LenList(result))) + trace.Step("Writing http response done", utiltrace.Field{"count", meta.LenList(result)}) } } diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/patch.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/patch.go index 7988b0a2fa4..125955618e5 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/patch.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/patch.go @@ -59,7 +59,7 @@ const ( func PatchResource(r rest.Patcher, scope *RequestScope, admit admission.Interface, patchTypes []string) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { // For performance tracking purposes. - trace := utiltrace.New("Patch " + req.URL.Path) + trace := utiltrace.New("Patch", utiltrace.Field{"url", req.URL.Path}) defer trace.LogIfLong(500 * time.Millisecond) if isDryRun(req.URL) && !utilfeature.DefaultFeatureGate.Enabled(features.DryRun) { diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/rest_test.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/rest_test.go index 568325b27c5..d3a18805960 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/rest_test.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/rest_test.go @@ -463,7 +463,7 @@ func (tc *patchTestCase) Run(t *testing.T) { patchType: patchType, patchBytes: patch, - trace: utiltrace.New("Patch" + name), + trace: utiltrace.New("Patch", utiltrace.Field{"name", name}), } resultObj, _, err := p.patchResource(ctx, &RequestScope{}) diff --git a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/update.go b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/update.go index f3aec87b396..f57062e8e91 100644 --- a/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/update.go +++ b/staging/src/k8s.io/apiserver/pkg/endpoints/handlers/update.go @@ -45,7 +45,7 @@ import ( func UpdateResource(r rest.Updater, scope *RequestScope, admit admission.Interface) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { // For performance tracking purposes. - trace := utiltrace.New("Update " + req.URL.Path) + trace := utiltrace.New("Update", utiltrace.Field{"url", req.URL.Path}) defer trace.LogIfLong(500 * time.Millisecond) if isDryRun(req.URL) && !utilfeature.DefaultFeatureGate.Enabled(features.DryRun) { diff --git a/staging/src/k8s.io/apiserver/pkg/storage/cacher/cacher.go b/staging/src/k8s.io/apiserver/pkg/storage/cacher/cacher.go index e589a97356f..65ef690f484 100644 --- a/staging/src/k8s.io/apiserver/pkg/storage/cacher/cacher.go +++ b/staging/src/k8s.io/apiserver/pkg/storage/cacher/cacher.go @@ -604,7 +604,7 @@ func (c *Cacher) GetToList(ctx context.Context, key string, resourceVersion stri return c.storage.GetToList(ctx, key, resourceVersion, pred, listObj) } - trace := utiltrace.New(fmt.Sprintf("cacher %v: List", c.objectType.String())) + trace := utiltrace.New("cacher list", utiltrace.Field{"type", c.objectType.String()}) defer trace.LogIfLong(500 * time.Millisecond) c.ready.wait() @@ -673,7 +673,7 @@ func (c *Cacher) List(ctx context.Context, key string, resourceVersion string, p return c.storage.List(ctx, key, resourceVersion, pred, listObj) } - trace := utiltrace.New(fmt.Sprintf("cacher %v: List", c.objectType.String())) + trace := utiltrace.New("cacher list", utiltrace.Field{"type", c.objectType.String()}) defer trace.LogIfLong(500 * time.Millisecond) c.ready.wait() @@ -694,7 +694,7 @@ func (c *Cacher) List(ctx context.Context, key string, resourceVersion string, p if err != nil { return err } - trace.Step(fmt.Sprintf("Listed %d items from cache", len(objs))) + trace.Step("Listed items from cache", utiltrace.Field{"count", len(objs)}) if len(objs) > listVal.Cap() && pred.Label.Empty() && pred.Field.Empty() { // Resize the slice appropriately, since we already know that none // of the elements will be filtered out. @@ -710,7 +710,7 @@ func (c *Cacher) List(ctx context.Context, key string, resourceVersion string, p listVal.Set(reflect.Append(listVal, reflect.ValueOf(elem.Object).Elem())) } } - trace.Step(fmt.Sprintf("Filtered %d items", listVal.Len())) + trace.Step("Filtered items", utiltrace.Field{"count", listVal.Len()}) if c.versioner != nil { if err := c.versioner.UpdateList(listObj, readResourceVersion, "", nil); err != nil { return err diff --git a/staging/src/k8s.io/apiserver/pkg/storage/etcd3/store.go b/staging/src/k8s.io/apiserver/pkg/storage/etcd3/store.go index bd84f2804bb..ba1953f4919 100644 --- a/staging/src/k8s.io/apiserver/pkg/storage/etcd3/store.go +++ b/staging/src/k8s.io/apiserver/pkg/storage/etcd3/store.go @@ -236,7 +236,7 @@ func (s *store) conditionalDelete(ctx context.Context, key string, out runtime.O func (s *store) GuaranteedUpdate( ctx context.Context, key string, out runtime.Object, ignoreNotFound bool, preconditions *storage.Preconditions, tryUpdate storage.UpdateFunc, suggestion ...runtime.Object) error { - trace := utiltrace.New(fmt.Sprintf("GuaranteedUpdate etcd3: %s", getTypeName(out))) + trace := utiltrace.New("GuaranteedUpdate etcd3", utiltrace.Field{"type", getTypeName(out)}) defer trace.LogIfLong(500 * time.Millisecond) v, err := conversion.EnforcePtr(out) @@ -363,7 +363,11 @@ func (s *store) GuaranteedUpdate( // GetToList implements storage.Interface.GetToList. func (s *store) GetToList(ctx context.Context, key string, resourceVersion string, pred storage.SelectionPredicate, listObj runtime.Object) error { - trace := utiltrace.New(fmt.Sprintf("GetToList etcd3: key=%v, resourceVersion=%s, limit: %d, continue: %s", key, resourceVersion, pred.Limit, pred.Continue)) + trace := utiltrace.New("GetToList etcd3", + utiltrace.Field{"key", key}, + utiltrace.Field{"resourceVersion", resourceVersion}, + utiltrace.Field{"limit", pred.Limit}, + utiltrace.Field{"continue", pred.Continue}) defer trace.LogIfLong(500 * time.Millisecond) listPtr, err := meta.GetItemsPtr(listObj) if err != nil { @@ -468,7 +472,11 @@ func encodeContinue(key, keyPrefix string, resourceVersion int64) (string, error // List implements storage.Interface.List. func (s *store) List(ctx context.Context, key, resourceVersion string, pred storage.SelectionPredicate, listObj runtime.Object) error { - trace := utiltrace.New(fmt.Sprintf("List etcd3: key=%v, resourceVersion=%s, limit: %d, continue: %s", key, resourceVersion, pred.Limit, pred.Continue)) + trace := utiltrace.New("List etcd3", + utiltrace.Field{"key", key}, + utiltrace.Field{"resourceVersion", resourceVersion}, + utiltrace.Field{"limit", pred.Limit}, + utiltrace.Field{"continue", pred.Continue}) defer trace.LogIfLong(500 * time.Millisecond) listPtr, err := meta.GetItemsPtr(listObj) if err != nil { diff --git a/staging/src/k8s.io/apiserver/plugin/pkg/audit/webhook/webhook.go b/staging/src/k8s.io/apiserver/plugin/pkg/audit/webhook/webhook.go index ece92eedd55..ae789a3b33f 100644 --- a/staging/src/k8s.io/apiserver/plugin/pkg/audit/webhook/webhook.go +++ b/staging/src/k8s.io/apiserver/plugin/pkg/audit/webhook/webhook.go @@ -96,7 +96,9 @@ func (b *backend) processEvents(ev ...*auditinternal.Event) error { list.Items = append(list.Items, *e) } return b.w.WithExponentialBackoff(func() rest.Result { - trace := utiltrace.New(fmt.Sprintf("Audit events webhook request for %s, event list count: %d", b.name, len(list.Items))) + trace := utiltrace.New("Call Audit Events webhook", + utiltrace.Field{"name", b.name}, + utiltrace.Field{"event-count", len(list.Items)}) // Only log audit webhook traces that exceed a 25ms per object limit plus a 50ms // request overhead allowance. The high per object limit used here is primarily to // allow enough time for the serialization/deserialization of audit events, which diff --git a/staging/src/k8s.io/client-go/tools/cache/reflector.go b/staging/src/k8s.io/client-go/tools/cache/reflector.go index b7e67c0ef0c..4c14aaf7875 100644 --- a/staging/src/k8s.io/client-go/tools/cache/reflector.go +++ b/staging/src/k8s.io/client-go/tools/cache/reflector.go @@ -166,7 +166,7 @@ func (r *Reflector) ListAndWatch(stopCh <-chan struct{}) error { options := metav1.ListOptions{ResourceVersion: "0"} if err := func() error { - initTrace := trace.New("Reflector " + r.name + " ListAndWatch") + initTrace := trace.New("Reflector ListAndWatch", trace.Field{"name", r.name}) defer initTrace.LogIfLong(10 * time.Second) var list runtime.Object var err error