diff --git a/internal/cli/cli_test.go b/internal/cli/cli_test.go index 4b7acec..f66dff2 100644 --- a/internal/cli/cli_test.go +++ b/internal/cli/cli_test.go @@ -584,7 +584,8 @@ func TestRunVMCreatePollsUntilDone(t *testing.T) { return nil } - got, err := d.runVMCreate(context.Background(), "/tmp/bangerd.sock", &bytes.Buffer{}, api.VMCreateParams{Name: "devbox"}) + var stderr bytes.Buffer + got, err := d.runVMCreate(context.Background(), "/tmp/bangerd.sock", &stderr, api.VMCreateParams{Name: "devbox"}) if err != nil { t.Fatalf("d.runVMCreate: %v", err) } @@ -594,6 +595,27 @@ func TestRunVMCreatePollsUntilDone(t *testing.T) { if statusCalls != 2 { t.Fatalf("statusCalls = %d, want 2", statusCalls) } + if !strings.Contains(stderr.String(), "[vm create] ready in ") { + t.Fatalf("stderr missing elapsed line:\n%s", stderr.String()) + } +} + +func TestFormatVMCreateElapsed(t *testing.T) { + cases := []struct { + in time.Duration + want string + }{ + {350 * time.Millisecond, "350ms"}, + {4*time.Second + 700*time.Millisecond, "4.7s"}, + {59*time.Second + 900*time.Millisecond, "59.9s"}, + {62 * time.Second, "1m02s"}, + {2*time.Minute + 5*time.Second, "2m05s"}, + } + for _, tc := range cases { + if got := formatVMCreateElapsed(tc.in); got != tc.want { + t.Errorf("formatVMCreateElapsed(%s) = %q, want %q", tc.in, got, tc.want) + } + } } func TestVMCreateProgressRendererSuppressesDuplicateLines(t *testing.T) { diff --git a/internal/cli/vm_create.go b/internal/cli/vm_create.go index a1e8238..e72f197 100644 --- a/internal/cli/vm_create.go +++ b/internal/cli/vm_create.go @@ -61,6 +61,7 @@ func printVMSpecLine(out io.Writer, params api.VMCreateParams) { // On context cancel we cooperate with the daemon to cancel the // in-flight op so it doesn't leak partially-created VM state. func (d *deps) runVMCreate(ctx context.Context, socketPath string, stderr io.Writer, params api.VMCreateParams) (model.VMRecord, error) { + start := time.Now() printVMSpecLine(stderr, params) begin, err := d.vmCreateBegin(ctx, socketPath, params) if err != nil { @@ -74,6 +75,7 @@ func (d *deps) runVMCreate(ctx context.Context, socketPath string, stderr io.Wri if op.Done { renderer.render(op) if op.Success && op.VM != nil { + _, _ = fmt.Fprintf(stderr, "[vm create] ready in %s\n", formatVMCreateElapsed(time.Since(start))) return *op.VM, nil } if strings.TrimSpace(op.Error) == "" { @@ -231,6 +233,22 @@ func vmCreateStageLabel(stage string) string { } } +// formatVMCreateElapsed renders a wall-clock duration as a friendly +// "ready in 4.7s" / "ready in 1m02s" string. Sub-second durations +// keep one decimal so quick smoke runs don't print "0s". +func formatVMCreateElapsed(d time.Duration) string { + if d < time.Second { + return fmt.Sprintf("%dms", d.Milliseconds()) + } + if d < time.Minute { + return fmt.Sprintf("%.1fs", d.Seconds()) + } + d = d.Round(time.Second) + minutes := int(d / time.Minute) + seconds := int((d % time.Minute) / time.Second) + return fmt.Sprintf("%dm%02ds", minutes, seconds) +} + func validatePositiveSetting(label string, value int) error { if value <= 0 { return fmt.Errorf("%s must be a positive integer", label)