diff --git a/integration/skaffold/helper.go b/integration/skaffold/helper.go index 20f974cd1ae..6f717f39677 100644 --- a/integration/skaffold/helper.go +++ b/integration/skaffold/helper.go @@ -214,7 +214,7 @@ func (b *RunBuilder) runForked(t *testing.T, out io.Writer) { go func() { cmd.Wait() - logrus.Infoln("Ran in", time.Since(start)) + logrus.Infoln("Ran in", util.ShowHumanizeTime(time.Since(start))) }() t.Cleanup(func() { @@ -240,8 +240,7 @@ func (b *RunBuilder) Run(t *testing.T) error { if err := cmd.Run(); err != nil { return fmt.Errorf("skaffold %q: %w", b.command, err) } - - logrus.Infoln("Ran in", time.Since(start)) + logrus.Infoln("Ran in", util.ShowHumanizeTime(time.Since(start))) return nil } @@ -258,8 +257,7 @@ func (b *RunBuilder) RunWithCombinedOutput(t *testing.T) ([]byte, error) { if err != nil { return out, fmt.Errorf("skaffold %q: %w", b.command, err) } - - logrus.Infoln("Ran in", time.Since(start)) + logrus.Infoln("Ran in", util.ShowHumanizeTime(time.Since(start))) return out, nil } @@ -281,8 +279,7 @@ func (b *RunBuilder) RunOrFailOutput(t *testing.T) []byte { } t.Fatalf("skaffold %s: %v, %s", b.command, err, out) } - - logrus.Infoln("Ran in", time.Since(start)) + logrus.Infoln("Ran in", util.ShowHumanizeTime(time.Since(start))) return out } diff --git a/pkg/skaffold/build/cache/retrieve.go b/pkg/skaffold/build/cache/retrieve.go index 130438a3760..c1388cc71c1 100644 --- a/pkg/skaffold/build/cache/retrieve.go +++ b/pkg/skaffold/build/cache/retrieve.go @@ -30,6 +30,7 @@ import ( "github.com/GoogleContainerTools/skaffold/pkg/skaffold/docker" sErrors "github.com/GoogleContainerTools/skaffold/pkg/skaffold/errors" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest" + "github.com/GoogleContainerTools/skaffold/pkg/skaffold/util" ) func (c *cache) Build(ctx context.Context, out io.Writer, tags tag.ImageTags, artifacts []*latest.Artifact, buildAndTest BuildAndTestFn) ([]build.Artifact, error) { @@ -119,7 +120,7 @@ func (c *cache) Build(ctx context.Context, out io.Writer, tags tag.ImageTags, ar }) } - logrus.Infoln("Cache check complete in", time.Since(start)) + logrus.Infoln("Cache check completed in", util.ShowHumanizeTime(time.Since(start))) bRes, err := buildAndTest(ctx, out, tags, needToBuild) if err != nil { diff --git a/pkg/skaffold/diagnose/diagnose.go b/pkg/skaffold/diagnose/diagnose.go index d467dc0238a..d6a7d7957ee 100644 --- a/pkg/skaffold/diagnose/diagnose.go +++ b/pkg/skaffold/diagnose/diagnose.go @@ -29,6 +29,7 @@ import ( "github.com/GoogleContainerTools/skaffold/pkg/skaffold/filemon" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/sync" + "github.com/GoogleContainerTools/skaffold/pkg/skaffold/util" ) type Config interface { @@ -112,26 +113,25 @@ func typeOfArtifact(a *latest.Artifact) string { } } -func timeToListDependencies(ctx context.Context, a *latest.Artifact, cfg docker.Config) (time.Duration, []string, error) { +func timeToListDependencies(ctx context.Context, a *latest.Artifact, cfg docker.Config) (string, []string, error) { start := time.Now() paths, err := build.DependenciesForArtifact(ctx, a, cfg, nil) - return time.Since(start), paths, err + return util.ShowHumanizeTime(time.Since(start)), paths, err } -func timeToConstructSyncMap(a *latest.Artifact, cfg docker.Config) (time.Duration, error) { +func timeToConstructSyncMap(a *latest.Artifact, cfg docker.Config) (string, error) { start := time.Now() _, err := sync.SyncMap(a, cfg) - return time.Since(start), err + return util.ShowHumanizeTime(time.Since(start)), err } -func timeToComputeMTimes(deps []string) (time.Duration, error) { +func timeToComputeMTimes(deps []string) (string, error) { start := time.Now() if _, err := filemon.Stat(func() ([]string, error) { return deps, nil }); err != nil { - return 0, fmt.Errorf("computing modTimes: %w", err) + return "nil", fmt.Errorf("computing modTimes: %w", err) } - - return time.Since(start), nil + return util.ShowHumanizeTime(time.Since(start)), nil } func sizeOfDockerContext(ctx context.Context, a *latest.Artifact, cfg docker.Config) (int64, error) { diff --git a/pkg/skaffold/runner/build_deploy.go b/pkg/skaffold/runner/build_deploy.go index c66db8ae5c6..53203c65f21 100644 --- a/pkg/skaffold/runner/build_deploy.go +++ b/pkg/skaffold/runner/build_deploy.go @@ -30,6 +30,7 @@ import ( "github.com/GoogleContainerTools/skaffold/pkg/skaffold/color" deployutil "github.com/GoogleContainerTools/skaffold/pkg/skaffold/deploy/util" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest" + "github.com/GoogleContainerTools/skaffold/pkg/skaffold/util" ) // Build builds a list of artifacts. @@ -212,7 +213,7 @@ func (r *SkaffoldRunner) imageTags(ctx context.Context, out io.Writer, artifacts color.Yellow.Fprintln(out, "Some taggers failed. Rerun with -vdebug for errors.") } - logrus.Infoln("Tags generated in", time.Since(start)) + logrus.Infoln("Tags generated in", util.ShowHumanizeTime(time.Since(start))) return imageTags, nil } diff --git a/pkg/skaffold/runner/deploy.go b/pkg/skaffold/runner/deploy.go index 32593e421d4..dec55bacd70 100644 --- a/pkg/skaffold/runner/deploy.go +++ b/pkg/skaffold/runner/deploy.go @@ -32,6 +32,7 @@ import ( "github.com/GoogleContainerTools/skaffold/pkg/skaffold/event" kubernetesclient "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/client" kubectx "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/context" + "github.com/GoogleContainerTools/skaffold/pkg/skaffold/util" ) func (r *SkaffoldRunner) Deploy(ctx context.Context, out io.Writer, artifacts []build.Artifact) error { @@ -167,6 +168,6 @@ func (r *SkaffoldRunner) performStatusCheck(ctx context.Context, out io.Writer) return err } - color.Default.Fprintln(out, "Deployments stabilized in", time.Since(start)) + color.Default.Fprintln(out, "Deployments stabilized in", util.ShowHumanizeTime(time.Since(start))) return nil } diff --git a/pkg/skaffold/runner/dev.go b/pkg/skaffold/runner/dev.go index c50bccbec9d..7144fba098d 100644 --- a/pkg/skaffold/runner/dev.go +++ b/pkg/skaffold/runner/dev.go @@ -35,6 +35,7 @@ import ( "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/portforward" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/sync" + "github.com/GoogleContainerTools/skaffold/pkg/skaffold/util" "github.com/GoogleContainerTools/skaffold/proto" ) @@ -205,7 +206,7 @@ func (r *SkaffoldRunner) Dev(ctx context.Context, out io.Writer, artifacts []*la return fmt.Errorf("watching skaffold configuration %q: %w", r.runCtx.ConfigurationFile(), err) } - logrus.Infoln("List generated in", time.Since(start)) + logrus.Infoln("List generated in", util.ShowHumanizeTime(time.Since(start))) // Init Sync State if err := sync.Init(ctx, artifacts); err != nil { diff --git a/pkg/skaffold/runner/load_images.go b/pkg/skaffold/runner/load_images.go index 6d23f6d56eb..51dee61af75 100644 --- a/pkg/skaffold/runner/load_images.go +++ b/pkg/skaffold/runner/load_images.go @@ -86,7 +86,7 @@ func (r *SkaffoldRunner) loadImages(ctx context.Context, out io.Writer, artifact color.Green.Fprintln(out, "Loaded") } - color.Default.Fprintln(out, "Images loaded in", time.Since(start)) + color.Default.Fprintln(out, "Images loaded in", util.ShowHumanizeTime(time.Since(start))) return nil } diff --git a/pkg/skaffold/runner/timings.go b/pkg/skaffold/runner/timings.go index 8377699fd4c..8f01cab28a6 100644 --- a/pkg/skaffold/runner/timings.go +++ b/pkg/skaffold/runner/timings.go @@ -29,6 +29,7 @@ import ( "github.com/GoogleContainerTools/skaffold/pkg/skaffold/deploy" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/schema/latest" "github.com/GoogleContainerTools/skaffold/pkg/skaffold/test" + "github.com/GoogleContainerTools/skaffold/pkg/skaffold/util" ) // WithTimings creates a deployer that logs the duration of each phase. @@ -60,8 +61,7 @@ func (w withTimings) Build(ctx context.Context, out io.Writer, tags tag.ImageTag if err != nil { return nil, err } - - logrus.Infoln("Build complete in", time.Since(start)) + logrus.Infoln("Build completed in", util.ShowHumanizeTime(time.Since(start))) return bRes, nil } @@ -72,8 +72,7 @@ func (w withTimings) Test(ctx context.Context, out io.Writer, builds []build.Art if err != nil { return err } - - logrus.Infoln("Test complete in", time.Since(start)) + logrus.Infoln("Test completed in", util.ShowHumanizeTime(time.Since(start))) return nil } @@ -85,8 +84,7 @@ func (w withTimings) Deploy(ctx context.Context, out io.Writer, builds []build.A if err != nil { return nil, err } - - logrus.Infoln("Deploy complete in", time.Since(start)) + logrus.Infoln("Deploy completed in", util.ShowHumanizeTime(time.Since(start))) return ns, err } @@ -98,8 +96,7 @@ func (w withTimings) Cleanup(ctx context.Context, out io.Writer) error { if err != nil { return err } - - logrus.Infoln("Cleanup complete in", time.Since(start)) + logrus.Infoln("Cleanup completed in", util.ShowHumanizeTime(time.Since(start))) return nil } @@ -111,7 +108,6 @@ func (w withTimings) Prune(ctx context.Context, out io.Writer) error { if err != nil { return err } - - logrus.Infoln("Image prune complete in", time.Since(start)) + logrus.Infoln("Image prune completed in", util.ShowHumanizeTime(time.Since(start))) return nil } diff --git a/pkg/skaffold/runner/timings_test.go b/pkg/skaffold/runner/timings_test.go index 1e109935fa5..d8afc56664e 100644 --- a/pkg/skaffold/runner/timings_test.go +++ b/pkg/skaffold/runner/timings_test.go @@ -94,7 +94,7 @@ func TestTimingsBuild(t *testing.T) { { description: "build success", shouldOutput: "", - shouldLog: "Build complete in .+$", + shouldLog: "Build completed in .+$", shouldErr: false, }, { @@ -130,7 +130,7 @@ func TestTimingsPrune(t *testing.T) { { description: "test success", shouldOutput: "(?m)^Pruning images...\n", - shouldLog: "Image prune complete in .+$", + shouldLog: "Image prune completed in .+$", shouldErr: false, }, { @@ -166,7 +166,7 @@ func TestTimingsTest(t *testing.T) { { description: "test success", shouldOutput: "", - shouldLog: "Test complete in .+$", + shouldLog: "Test completed in .+$", shouldErr: false, }, { @@ -202,7 +202,7 @@ func TestTimingsDeploy(t *testing.T) { { description: "prune success", shouldOutput: "(?m)^Starting deploy...\n", - shouldLog: "Deploy complete in .+$", + shouldLog: "Deploy completed in .+$", shouldErr: false, }, { @@ -238,7 +238,7 @@ func TestTimingsCleanup(t *testing.T) { { description: "cleanup success", shouldOutput: "(?m)^Cleaning up...\n", - shouldLog: "Cleanup complete in .+$", + shouldLog: "Cleanup completed in .+$", shouldErr: false, }, { diff --git a/pkg/skaffold/util/util.go b/pkg/skaffold/util/util.go index a8e51f20368..91e7a579b01 100644 --- a/pkg/skaffold/util/util.go +++ b/pkg/skaffold/util/util.go @@ -27,6 +27,7 @@ import ( "regexp" "sort" "strings" + "time" "github.com/sirupsen/logrus" @@ -341,3 +342,28 @@ func IsSubPath(basepath string, targetpath string) bool { func hasHiddenPrefix(s string) bool { return strings.HasPrefix(s, hiddenPrefix) } + +// ShowHumanizeTime returns time in human readable format +func ShowHumanizeTime(start time.Duration) string { + shortTime := start.Truncate(time.Millisecond) + longTime := shortTime.String() + out := time.Time{}.Add(shortTime) + + if start.Seconds() < 1 { + return start.String() + } + + longTime = strings.ReplaceAll(longTime, "h", " hour ") + longTime = strings.ReplaceAll(longTime, "m", " minute ") + longTime = strings.ReplaceAll(longTime, "s", " second") + if out.Hour() > 1 { + longTime = strings.ReplaceAll(longTime, "hour", "hours") + } + if out.Minute() > 1 { + longTime = strings.ReplaceAll(longTime, "minute", "minutes") + } + if out.Second() > 1 { + longTime = strings.ReplaceAll(longTime, "second", "seconds") + } + return longTime +} diff --git a/pkg/skaffold/util/util_test.go b/pkg/skaffold/util/util_test.go index 0423803698a..91df2f7761e 100644 --- a/pkg/skaffold/util/util_test.go +++ b/pkg/skaffold/util/util_test.go @@ -19,6 +19,7 @@ package util import ( "path/filepath" "testing" + "time" "github.com/mitchellh/go-homedir" @@ -468,3 +469,36 @@ func TestIsURL(t *testing.T) { func stringPointer(s string) *string { return &s } + +func TestShowHumanizeTime(t *testing.T) { + duration1, err := time.ParseDuration("1h58m30.918273645s") + if err != nil { + t.Errorf("%s", err) + } + duration2, err := time.ParseDuration("5.23494327s") + if err != nil { + t.Errorf("%s", err) + } + tests := []struct { + description string + value time.Duration + expected string + }{ + { + description: "Case for 1h58m30.918273645s", + value: duration1, + expected: "1 hour 58 minutes 30.918 seconds", + }, + { + description: "Case for 5.23494327s", + value: duration2, + expected: "5.234 seconds", + }, + } + for _, test := range tests { + testutil.Run(t, test.description, func(t *testutil.T) { + humanizedValue := ShowHumanizeTime(test.value) + t.CheckDeepEqual(test.expected, humanizedValue) + }) + } +}