From 170e0a2d9419ffc1317d65a80565585aa0332aa0 Mon Sep 17 00:00:00 2001 From: dlorenc Date: Thu, 10 Jan 2019 13:27:55 -0700 Subject: [PATCH] Add a lot more timing data. (#518) --- cmd/executor/cmd/root.go | 17 +++++++++++++++++ pkg/executor/build.go | 14 -------------- pkg/executor/push.go | 3 +++ pkg/snapshot/layered_map.go | 3 +++ pkg/snapshot/snapshot.go | 6 ++++++ pkg/timing/timing.go | 4 ++-- 6 files changed, 31 insertions(+), 16 deletions(-) diff --git a/cmd/executor/cmd/root.go b/cmd/executor/cmd/root.go index 4f7aea7ac..dac109c49 100644 --- a/cmd/executor/cmd/root.go +++ b/cmd/executor/cmd/root.go @@ -24,6 +24,8 @@ import ( "strings" "time" + "github.com/GoogleContainerTools/kaniko/pkg/timing" + "github.com/GoogleContainerTools/kaniko/pkg/buildcontext" "github.com/GoogleContainerTools/kaniko/pkg/config" "github.com/GoogleContainerTools/kaniko/pkg/constants" @@ -87,6 +89,21 @@ var RootCmd = &cobra.Command{ if err := executor.DoPush(image, opts); err != nil { exit(errors.Wrap(err, "error pushing image")) } + + benchmarkFile := os.Getenv("BENCHMARK_FILE") + // false is a keyword for integration tests to turn off benchmarking + if benchmarkFile != "" && benchmarkFile != "false" { + f, err := os.Create(benchmarkFile) + if err != nil { + logrus.Warnf("Unable to create benchmarking file %s: %s", benchmarkFile, err) + } + defer f.Close() + s, err := timing.JSON() + if err != nil { + logrus.Warnf("Unable to write benchmark file: %s", err) + } + f.WriteString(s) + } }, } diff --git a/pkg/executor/build.go b/pkg/executor/build.go index 26bf1972a..2ee22b02c 100644 --- a/pkg/executor/build.go +++ b/pkg/executor/build.go @@ -382,20 +382,6 @@ func DoBuild(opts *config.KanikoOptions) (v1.Image, error) { } } timing.DefaultRun.Stop(t) - benchmarkFile := os.Getenv("BENCHMARK_FILE") - // false is a keyword for integration tests to turn off benchmarking - if benchmarkFile != "" && benchmarkFile != "false" { - f, err := os.Create(benchmarkFile) - if err != nil { - logrus.Warnf("Unable to create benchmarking file %s: %s", benchmarkFile, err) - } - defer f.Close() - s, err := timing.JSON() - if err != nil { - logrus.Warnf("Unable to write benchmark file: %s", err) - } - f.WriteString(s) - } return sourceImage, nil } if stage.SaveStage { diff --git a/pkg/executor/push.go b/pkg/executor/push.go index e6106efac..77c0d0ee7 100644 --- a/pkg/executor/push.go +++ b/pkg/executor/push.go @@ -25,6 +25,7 @@ import ( "github.com/GoogleContainerTools/kaniko/pkg/cache" "github.com/GoogleContainerTools/kaniko/pkg/config" "github.com/GoogleContainerTools/kaniko/pkg/constants" + "github.com/GoogleContainerTools/kaniko/pkg/timing" "github.com/GoogleContainerTools/kaniko/pkg/version" "github.com/google/go-containerregistry/pkg/authn" "github.com/google/go-containerregistry/pkg/authn/k8schain" @@ -53,6 +54,7 @@ func DoPush(image v1.Image, opts *config.KanikoOptions) error { logrus.Info("Skipping push to container registry due to --no-push flag") return nil } + t := timing.Start("Total Push Time") destRefs := []name.Tag{} for _, destination := range opts.Destinations { destRef, err := name.NewTag(destination, name.WeakValidation) @@ -103,6 +105,7 @@ func DoPush(image v1.Image, opts *config.KanikoOptions) error { return errors.Wrap(err, fmt.Sprintf("failed to push to destination %s", destRef)) } } + timing.DefaultRun.Stop(t) return nil } diff --git a/pkg/snapshot/layered_map.go b/pkg/snapshot/layered_map.go index c84340e36..16d9e36e1 100644 --- a/pkg/snapshot/layered_map.go +++ b/pkg/snapshot/layered_map.go @@ -23,6 +23,7 @@ import ( "path/filepath" "strings" + "github.com/GoogleContainerTools/kaniko/pkg/timing" "github.com/GoogleContainerTools/kaniko/pkg/util" ) @@ -124,6 +125,8 @@ func (l *LayeredMap) Add(s string) error { // was added. func (l *LayeredMap) MaybeAdd(s string) (bool, error) { oldV, ok := l.Get(s) + t := timing.Start("Hashing files") + defer timing.DefaultRun.Stop(t) newV, err := l.hasher(s) if err != nil { return false, err diff --git a/pkg/snapshot/snapshot.go b/pkg/snapshot/snapshot.go index b73018b81..a35d07ffa 100644 --- a/pkg/snapshot/snapshot.go +++ b/pkg/snapshot/snapshot.go @@ -22,6 +22,8 @@ import ( "path/filepath" "syscall" + "github.com/GoogleContainerTools/kaniko/pkg/timing" + "github.com/karrick/godirwalk" "github.com/GoogleContainerTools/kaniko/pkg/constants" @@ -141,6 +143,7 @@ func (s *Snapshotter) TakeSnapshotFS() (string, error) { t := util.NewTar(f) defer t.Close() + timer := timing.Start("Walking filesystem") // Save the fs state in a map to iterate over later. memFs := map[string]*godirwalk.Dirent{} godirwalk.Walk(s.directory, &godirwalk.Options{ @@ -158,6 +161,7 @@ func (s *Snapshotter) TakeSnapshotFS() (string, error) { Unsorted: true, }, ) + timing.DefaultRun.Stop(timer) // First handle whiteouts for p := range memFs { @@ -176,6 +180,7 @@ func (s *Snapshotter) TakeSnapshotFS() (string, error) { } } + timer = timing.Start("Writing tar file") // Now create the tar. for path := range memFs { whitelisted, err := util.CheckWhitelist(path) @@ -198,6 +203,7 @@ func (s *Snapshotter) TakeSnapshotFS() (string, error) { } } } + timing.DefaultRun.Stop(timer) return f.Name(), nil } diff --git a/pkg/timing/timing.go b/pkg/timing/timing.go index edbc1a4f7..2d1103d96 100644 --- a/pkg/timing/timing.go +++ b/pkg/timing/timing.go @@ -39,11 +39,11 @@ type TimedRun struct { // Stop stops the specified timer and increments the time spent in that category. func (tr *TimedRun) Stop(t *Timer) { stop := currentTimeFunc() + tr.cl.Lock() + defer tr.cl.Unlock() if _, ok := tr.categories[t.category]; !ok { tr.categories[t.category] = 0 } - tr.cl.Lock() - defer tr.cl.Unlock() tr.categories[t.category] += stop.Sub(t.startTime) }