Improve CLI output: phase markers, timings, summary table

console.go

@@ -0,0 +1,149 @@
+package main
+
+import (
+	"fmt"
+	"io"
+	"os"
+	"text/tabwriter"
+	"time"
+
+	"github.com/fatih/color"
+
+	"github.com/pg-tools/pgcompare/internal/pgcompare"
+)
+
+const consoleWidth = 68
+
+var (
+	colArrow   = color.New(color.FgCyan, color.Bold)
+	colOK      = color.New(color.FgGreen, color.Bold)
+	colFail    = color.New(color.FgRed, color.Bold)
+	colTime    = color.New(color.FgHiBlack)
+	colRule    = color.New(color.FgHiBlack)
+	colGood    = color.New(color.FgGreen)
+	colNeutral = color.New(color.FgYellow)
+	colBad     = color.New(color.FgRed)
+	colDim     = color.New(color.FgHiBlack)
+)
+
+type phase struct {
+	name    string
+	started time.Time
+	out     io.Writer
+}
+
+func startPhase(name string) *phase {
+	out := os.Stderr
+	colArrow.Fprint(out, "▶ ")
+	fmt.Fprintln(out, name)
+	return &phase{name: name, started: time.Now(), out: out}
+}
+
+func (p *phase) Done() time.Duration {
+	elapsed := time.Since(p.started)
+	colOK.Fprint(p.out, "✓ ")
+	pad := consoleWidth - 2 - len(p.name)
+	if pad < 1 {
+		pad = 1
+	}
+	fmt.Fprintf(p.out, "%s%s", p.name, spaces(pad))
+	colTime.Fprintf(p.out, "[%s]\n", formatDuration(elapsed))
+	fmt.Fprintln(p.out)
+	return elapsed
+}
+
+func (p *phase) Fail(err error) time.Duration {
+	elapsed := time.Since(p.started)
+	colFail.Fprint(p.out, "✗ ")
+	pad := consoleWidth - 2 - len(p.name)
+	if pad < 1 {
+		pad = 1
+	}
+	fmt.Fprintf(p.out, "%s%s", p.name, spaces(pad))
+	colTime.Fprintf(p.out, "[%s]\n", formatDuration(elapsed))
+	if err != nil {
+		colFail.Fprintf(p.out, "  %s\n", err.Error())
+	}
+	fmt.Fprintln(p.out)
+	return elapsed
+}
+
+func printHeader(title string) {
+	out := os.Stderr
+	rule := ""
+	padLen := consoleWidth - len(title) - 8
+	if padLen < 3 {
+		padLen = 3
+	}
+	for i := 0; i < padLen; i++ {
+		rule += "━"
+	}
+	colRule.Fprintf(out, "━━━ %s ", title)
+	colRule.Fprintln(out, rule)
+}
+
+func printSummary(data pgcompare.ReportData, outPath string, total time.Duration) {
+	out := os.Stderr
+	fmt.Fprintln(out)
+	printHeader("Summary")
+
+	tw := tabwriter.NewWriter(out, 0, 0, 2, ' ', 0)
+	colDim.Fprintln(tw, "  Query\tBefore P95\tAfter P95\tSpeedup\t")
+	for i, s := range data.Before.Stats {
+		after := data.After.Stats[i]
+		sp := 0.0
+		if i < len(data.Speedups) {
+			sp = data.Speedups[i]
+		}
+		marker, markColor := speedupMarker(sp)
+		fmt.Fprintf(tw, "  %s\t%s\t%s\t%s  %s\t\n",
+			s.QueryName,
+			formatLatency(s.P95),
+			formatLatency(after.P95),
+			markColor.Sprintf("%.1f×", sp),
+			markColor.Sprint(marker),
+		)
+	}
+	tw.Flush()
+
+	fmt.Fprintln(out)
+	colDim.Fprintf(out, "  Total: %s · Report: ", formatDuration(total))
+	fmt.Fprintln(out, outPath)
+}
+
+func speedupMarker(sp float64) (string, *color.Color) {
+	switch {
+	case sp >= 1.1:
+		return "✓", colGood
+	case sp >= 0.9:
+		return "~", colNeutral
+	default:
+		return "✗", colBad
+	}
+}
+
+func formatDuration(d time.Duration) string {
+	if d < time.Second {
+		return fmt.Sprintf("%dms", d.Milliseconds())
+	}
+	return fmt.Sprintf("%.1fs", d.Seconds())
+}
+
+func formatLatency(d time.Duration) string {
+	us := d.Microseconds()
+	if us < 1000 {
+		return fmt.Sprintf("%dµs", us)
+	}
+	return fmt.Sprintf("%.1fms", float64(us)/1000)
+}
+
+func spaces(n int) string {
+	if n <= 0 {
+		return ""
+	}
+	b := make([]byte, n)
+	for i := range b {
+		b[i] = ' '
+	}
+	return string(b)
+}

go.mod

@@ -3,6 +3,7 @@ module github.com/pg-tools/pgcompare
 go 1.25.0
 
 require (
+	github.com/fatih/color v1.19.0
 	github.com/jackc/pgx/v5 v5.9.1
 	github.com/joho/godotenv v1.5.1
 	github.com/spf13/cobra v1.10.2
@@ -17,9 +18,12 @@ require (
 	github.com/jackc/pgservicefile v0.0.0-20240606120523-5a60cdf6a761 // indirect
 	github.com/jackc/puddle/v2 v2.2.2 // indirect
 	github.com/kr/text v0.2.0 // indirect
+	github.com/mattn/go-colorable v0.1.14 // indirect
+	github.com/mattn/go-isatty v0.0.20 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
 	github.com/rogpeppe/go-internal v1.14.1 // indirect
 	github.com/spf13/pflag v1.0.9 // indirect
 	golang.org/x/sync v0.17.0 // indirect
+	golang.org/x/sys v0.42.0 // indirect
 	golang.org/x/text v0.29.0 // indirect
 )

go.sum

@@ -3,6 +3,8 @@ github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ3
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/fatih/color v1.19.0 h1:Zp3PiM21/9Ld6FzSKyL5c/BULoe/ONr9KlbYVOfG8+w=
+github.com/fatih/color v1.19.0/go.mod h1:zNk67I0ZUT1bEGsSGyCZYZNrHuTkJJB+r6Q9VuMi0LE=
 github.com/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8=
 github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw=
 github.com/jackc/pgpassfile v1.0.0 h1:/6Hmqy13Ss2zCq62VdNG8tM1wchn8zjSGOBJ6icpsIM=
@@ -19,6 +21,10 @@ github.com/kr/pretty v0.3.0 h1:WgNl7dwNpEZ6jJ9k1snq4pZsg7DOEN8hP9Xw0Tsjwk0=
 github.com/kr/pretty v0.3.0/go.mod h1:640gp4NfQd8pI5XOwp5fnNeVWj67G7CFk/SaSQn7NBk=
 github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY=
 github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE=
+github.com/mattn/go-colorable v0.1.14 h1:9A9LHSqF/7dyVVX6g0U9cwm9pG3kP9gSzcuIPHPsaIE=
+github.com/mattn/go-colorable v0.1.14/go.mod h1:6LmQG8QLFO4G5z1gPvYEzlUgJ2wF+stgPZH1UqBm1s8=
+github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY=
+github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/rogpeppe/go-internal v1.14.1 h1:UQB4HGPB6osV0SQTLymcB4TgvyWu6ZyliaW0tI/otEQ=
@@ -36,6 +42,9 @@ github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD
 go.yaml.in/yaml/v3 v3.0.4/go.mod h1:DhzuOOF2ATzADvBadXxruRBLzYTpT36CKvDb3+aBEFg=
 golang.org/x/sync v0.17.0 h1:l60nONMj9l5drqw6jlhIELNv9I0A4OFgRsG9k2oT9Ug=
 golang.org/x/sync v0.17.0/go.mod h1:9KTHXmSnoGruLpwFjVSX0lNNA75CykiMECbovNTZqGI=
+golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.42.0 h1:omrd2nAlyT5ESRdCLYdm3+fMfNFE/+Rf4bDIQImRJeo=
+golang.org/x/sys v0.42.0/go.mod h1:4GL1E5IUh+htKOUEOaiffhrAeqysfVGipDYzABqnCmw=
 golang.org/x/text v0.29.0 h1:1neNs90w9YzJ9BocxfsQNHKuAT4pkghyXc4nhZ6sJvk=
 golang.org/x/text v0.29.0/go.mod h1:7MhJOA9CD2qZyOKYazxdYMF85OwPdEr9jTtBpO7ydH4=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=

main.go

@@ -98,16 +98,25 @@ func runBenchmark(_ *cobra.Command, _ []string) error {
 		}
 	}()
 
+	startAll := time.Now()
+	printHeader("pgcompare")
+
+	benchLabel := fmt.Sprintf("(%d repeat × %d iter × %d worker)",
+		cfg.Benchmark.Repeats, cfg.Benchmark.Iterations, cfg.Benchmark.Concurrency)
+
 	// Phase: before
-	fmt.Fprintln(os.Stderr, "Preparing 'before' environment...")
+	p := startPhase("Preparing 'before' environment")
 	if err := docker.PrepareVersion(ctx, cfg.Migration.BeforeVersion); err != nil {
+		p.Fail(err)
 		return fmt.Errorf("prepare before: %w", err)
 	}
 	if err := bench.ReadinessCheck(ctx, beforeQueries); err != nil {
+		p.Fail(err)
 		return fmt.Errorf("before readiness: %w", err)
 	}
+	p.Done()
 
-	fmt.Fprintln(os.Stderr, "Benchmarking 'before'...")
+	p = startPhase("Benchmarking 'before' " + benchLabel)
 	beforeStats, err := bench.RunRepeats(
 		ctx,
 		beforeQueries,
@@ -117,23 +126,29 @@ func runBenchmark(_ *cobra.Command, _ []string) error {
 		uint(cfg.Benchmark.WarmupIterations),
 	)
 	if err != nil {
+		p.Fail(err)
 		return fmt.Errorf("bench before: %w", err)
 	}
 	beforePlans, err := bench.Explain(ctx, beforeQueries)
 	if err != nil {
+		p.Fail(err)
 		return fmt.Errorf("explain before: %w", err)
 	}
+	p.Done()
 
 	// Phase: after
-	fmt.Fprintln(os.Stderr, "Preparing 'after' environment...")
+	p = startPhase("Preparing 'after' environment")
 	if err := docker.PrepareVersion(ctx, cfg.Migration.AfterVersion); err != nil {
+		p.Fail(err)
 		return fmt.Errorf("prepare after: %w", err)
 	}
 	if err := bench.ReadinessCheck(ctx, afterQueries); err != nil {
+		p.Fail(err)
 		return fmt.Errorf("after readiness: %w", err)
 	}
+	p.Done()
 
-	fmt.Fprintln(os.Stderr, "Benchmarking 'after'...")
+	p = startPhase("Benchmarking 'after' " + benchLabel)
 	afterStats, err := bench.RunRepeats(
 		ctx,
 		afterQueries,
@@ -143,12 +158,15 @@ func runBenchmark(_ *cobra.Command, _ []string) error {
 		uint(cfg.Benchmark.WarmupIterations),
 	)
 	if err != nil {
+		p.Fail(err)
 		return fmt.Errorf("bench after: %w", err)
 	}
 	afterPlans, err := bench.Explain(ctx, afterQueries)
 	if err != nil {
+		p.Fail(err)
 		return fmt.Errorf("explain after: %w", err)
 	}
+	p.Done()
 
 	// Analyze
 	diffs, err := bench.DiffPlans(beforeQueries, beforePlans, afterQueries, afterPlans)
@@ -184,11 +202,14 @@ func runBenchmark(_ *cobra.Command, _ []string) error {
 		Description: cfg.Report.Description,
 	}
 
-	fmt.Fprintln(os.Stderr, "Generating report...")
+	p = startPhase("Generating report")
 	if err := pgcompare.Generate(data, outPath); err != nil {
+		p.Fail(err)
 		return fmt.Errorf("generate report: %w", err)
 	}
+	p.Done()
 
+	printSummary(data, outPath, time.Since(startAll))
 	fmt.Println(outPath)
 	return nil
 }