From 788218d7bb951c84695995f16a72b7df2c4b2726 Mon Sep 17 00:00:00 2001 From: Wojciech Tyczynski Date: Thu, 3 Dec 2015 12:31:22 +0100 Subject: [PATCH] Better traces for api calls. --- pkg/apiserver/resthandler.go | 27 +++++++++++++++++++++++++++ pkg/registry/generic/etcd/etcd.go | 18 ------------------ 2 files changed, 27 insertions(+), 18 deletions(-) diff --git a/pkg/apiserver/resthandler.go b/pkg/apiserver/resthandler.go index 803230f5a5..2117f93c71 100644 --- a/pkg/apiserver/resthandler.go +++ b/pkg/apiserver/resthandler.go @@ -115,6 +115,9 @@ func getResourceHandler(scope RequestScope, getter getterFunc) restful.RouteFunc func GetResource(r rest.Getter, scope RequestScope) restful.RouteFunction { return getResourceHandler(scope, func(ctx api.Context, name string, req *restful.Request) (runtime.Object, error) { + // For performance tracking purposes. + trace := util.NewTrace("Get " + req.Request.URL.Path) + defer trace.LogIfLong(250 * time.Millisecond) return r.Get(ctx, name) }) } @@ -322,6 +325,10 @@ func ListResource(r rest.Lister, rw rest.Watcher, scope RequestScope, forceWatch func createHandler(r rest.NamedCreater, scope RequestScope, typer runtime.ObjectTyper, admit admission.Interface, includeName bool) restful.RouteFunction { return func(req *restful.Request, res *restful.Response) { + // For performance tracking purposes. + trace := util.NewTrace("Create " + req.Request.URL.Path) + defer trace.LogIfLong(250 * time.Millisecond) + w := res.ResponseWriter // TODO: we either want to remove timeout or document it (if we document, move timeout out of this function and declare it in api_installer) @@ -351,12 +358,14 @@ func createHandler(r rest.NamedCreater, scope RequestScope, typer runtime.Object } obj := r.New() + trace.Step("About to convert to expected version") // TODO this cleans up with proper typing if err := scope.Codec.DecodeIntoWithSpecifiedVersionKind(body, obj, scope.Kind); err != nil { err = transformDecodeError(typer, err, obj, body) errorJSON(err, scope.Codec, w) return } + trace.Step("Conversion done") if admit != nil && admit.Handles(admission.Create) { userInfo, _ := api.UserFrom(ctx) @@ -368,6 +377,7 @@ func createHandler(r rest.NamedCreater, scope RequestScope, typer runtime.Object } } + trace.Step("About to store object in database") result, err := finishRequest(timeout, func() (runtime.Object, error) { out, err := r.Create(ctx, name, obj) if status, ok := out.(*unversioned.Status); ok && err == nil && status.Code == 0 { @@ -379,11 +389,13 @@ func createHandler(r rest.NamedCreater, scope RequestScope, typer runtime.Object errorJSON(err, scope.Codec, w) return } + trace.Step("Object stored in database") if err := setSelfLink(result, req, scope.Namer); err != nil { errorJSON(err, scope.Codec, w) return } + trace.Step("Self-link added") write(http.StatusCreated, scope.Kind.GroupVersion(), scope.Codec, result, w, req.Request) } @@ -565,6 +577,10 @@ func patchResource(ctx api.Context, timeout time.Duration, versionedObj runtime. // UpdateResource returns a function that will handle a resource update func UpdateResource(r rest.Updater, scope RequestScope, typer runtime.ObjectTyper, admit admission.Interface) restful.RouteFunction { return func(req *restful.Request, res *restful.Response) { + // For performance tracking purposes. + trace := util.NewTrace("Update " + req.Request.URL.Path) + defer trace.LogIfLong(250 * time.Millisecond) + w := res.ResponseWriter // TODO: we either want to remove timeout or document it (if we document, move timeout out of this function and declare it in api_installer) @@ -585,11 +601,13 @@ func UpdateResource(r rest.Updater, scope RequestScope, typer runtime.ObjectType } obj := r.New() + trace.Step("About to convert to expected version") if err := scope.Codec.DecodeIntoWithSpecifiedVersionKind(body, obj, scope.Kind); err != nil { err = transformDecodeError(typer, err, obj, body) errorJSON(err, scope.Codec, w) return } + trace.Step("Conversion done") if err := checkName(obj, name, namespace, scope.Namer); err != nil { errorJSON(err, scope.Codec, w) @@ -606,6 +624,7 @@ func UpdateResource(r rest.Updater, scope RequestScope, typer runtime.ObjectType } } + trace.Step("About to store object in database") wasCreated := false result, err := finishRequest(timeout, func() (runtime.Object, error) { obj, created, err := r.Update(ctx, obj) @@ -616,11 +635,13 @@ func UpdateResource(r rest.Updater, scope RequestScope, typer runtime.ObjectType errorJSON(err, scope.Codec, w) return } + trace.Step("Object stored in database") if err := setSelfLink(result, req, scope.Namer); err != nil { errorJSON(err, scope.Codec, w) return } + trace.Step("Self-link added") status := http.StatusOK if wasCreated { @@ -633,6 +654,10 @@ func UpdateResource(r rest.Updater, scope RequestScope, typer runtime.ObjectType // DeleteResource returns a function that will handle a resource deletion func DeleteResource(r rest.GracefulDeleter, checkBody bool, scope RequestScope, admit admission.Interface) restful.RouteFunction { return func(req *restful.Request, res *restful.Response) { + // For performance tracking purposes. + trace := util.NewTrace("Delete " + req.Request.URL.Path) + defer trace.LogIfLong(250 * time.Millisecond) + w := res.ResponseWriter // TODO: we either want to remove timeout or document it (if we document, move timeout out of this function and declare it in api_installer) @@ -671,6 +696,7 @@ func DeleteResource(r rest.GracefulDeleter, checkBody bool, scope RequestScope, } } + trace.Step("About do delete object from database") result, err := finishRequest(timeout, func() (runtime.Object, error) { return r.Delete(ctx, name, options) }) @@ -678,6 +704,7 @@ func DeleteResource(r rest.GracefulDeleter, checkBody bool, scope RequestScope, errorJSON(err, scope.Codec, w) return } + trace.Step("Object deleted from database") // if the rest.Deleter returns a nil object, fill out a status. Callers may return a valid // object with the response. diff --git a/pkg/registry/generic/etcd/etcd.go b/pkg/registry/generic/etcd/etcd.go index faf6008306..e98fb6a6bf 100644 --- a/pkg/registry/generic/etcd/etcd.go +++ b/pkg/registry/generic/etcd/etcd.go @@ -18,8 +18,6 @@ package etcd import ( "fmt" - "reflect" - "time" "k8s.io/kubernetes/pkg/api" kubeerr "k8s.io/kubernetes/pkg/api/errors" @@ -32,7 +30,6 @@ import ( "k8s.io/kubernetes/pkg/registry/generic" "k8s.io/kubernetes/pkg/runtime" "k8s.io/kubernetes/pkg/storage" - "k8s.io/kubernetes/pkg/util" "k8s.io/kubernetes/pkg/watch" "github.com/golang/glog" @@ -198,8 +195,6 @@ func (e *Etcd) ListPredicate(ctx api.Context, m generic.Matcher, options *unvers // Create inserts a new item according to the unique key from the object. func (e *Etcd) Create(ctx api.Context, obj runtime.Object) (runtime.Object, error) { - trace := util.NewTrace("Create " + reflect.TypeOf(obj).String()) - defer trace.LogIfLong(time.Second) if err := rest.BeforeCreate(e.CreateStrategy, ctx, obj); err != nil { return nil, err } @@ -215,14 +210,12 @@ func (e *Etcd) Create(ctx api.Context, obj runtime.Object) (runtime.Object, erro if err != nil { return nil, err } - trace.Step("About to create object") out := e.NewFunc() if err := e.Storage.Create(ctx, key, obj, out, ttl); err != nil { err = etcderr.InterpretCreateError(err, e.EndpointName, name) err = rest.CheckGeneratedNameError(e.CreateStrategy, err, obj) return nil, err } - trace.Step("Object created") if e.AfterCreate != nil { if err := e.AfterCreate(out); err != nil { return nil, err @@ -240,8 +233,6 @@ func (e *Etcd) Create(ctx api.Context, obj runtime.Object) (runtime.Object, erro // or an error. If the registry allows create-on-update, the create flow will be executed. // A bool is returned along with the object and any errors, to indicate object creation. func (e *Etcd) Update(ctx api.Context, obj runtime.Object) (runtime.Object, bool, error) { - trace := util.NewTrace("Update " + reflect.TypeOf(obj).String()) - defer trace.LogIfLong(time.Second) name, err := e.ObjectNameFunc(obj) if err != nil { return nil, false, err @@ -344,17 +335,13 @@ func (e *Etcd) Update(ctx api.Context, obj runtime.Object) (runtime.Object, bool // Get retrieves the item from etcd. func (e *Etcd) Get(ctx api.Context, name string) (runtime.Object, error) { obj := e.NewFunc() - trace := util.NewTrace("Get " + reflect.TypeOf(obj).String()) - defer trace.LogIfLong(time.Second) key, err := e.KeyFunc(ctx, name) if err != nil { return nil, err } - trace.Step("About to read object") if err := e.Storage.Get(ctx, key, obj, false); err != nil { return nil, etcderr.InterpretGetError(err, e.EndpointName, name) } - trace.Step("Object read") if e.Decorator != nil { if err := e.Decorator(obj); err != nil { return nil, err @@ -376,9 +363,6 @@ func (e *Etcd) Delete(ctx api.Context, name string, options *api.DeleteOptions) } obj := e.NewFunc() - trace := util.NewTrace("Delete " + reflect.TypeOf(obj).String()) - defer trace.LogIfLong(time.Second) - trace.Step("About to read object") if err := e.Storage.Get(ctx, key, obj, false); err != nil { return nil, etcderr.InterpretDeleteError(err, e.EndpointName, name) } @@ -395,7 +379,6 @@ func (e *Etcd) Delete(ctx api.Context, name string, options *api.DeleteOptions) return e.finalizeDelete(obj, false) } if graceful { - trace.Step("Graceful deletion") out := e.NewFunc() lastGraceful := int64(0) err := e.Storage.GuaranteedUpdate( @@ -433,7 +416,6 @@ func (e *Etcd) Delete(ctx api.Context, name string, options *api.DeleteOptions) // delete immediately, or no graceful deletion supported out := e.NewFunc() - trace.Step("About to delete object") if err := e.Storage.Delete(ctx, key, out); err != nil { return nil, etcderr.InterpretDeleteError(err, e.EndpointName, name) }