diff --git a/pkg/lib/kptops/render.go b/pkg/lib/kptops/render.go index 120bfe4da6..8b8728b21c 100644 --- a/pkg/lib/kptops/render.go +++ b/pkg/lib/kptops/render.go @@ -16,16 +16,11 @@ package kptops import ( "context" - "fmt" - "io" - "os" fnresultv1 "github.com/kptdev/kpt/api/fnresult/v1" "github.com/kptdev/kpt/pkg/fn" - "github.com/kptdev/kpt/pkg/lib/pkg" "github.com/kptdev/kpt/pkg/lib/runneroptions" "github.com/kptdev/kpt/pkg/printer" - "k8s.io/klog/v2" "sigs.k8s.io/kustomize/kyaml/filesys" ) @@ -51,51 +46,5 @@ func (r *renderer) Render(ctx context.Context, pkg filesys.FileSystem, opts fn.R FileSystem: pkg, RunnerOptions: r.runnerOptions, } - return rr.Execute(printer.WithContext(ctx, &packagePrinter{})) -} - -type packagePrinter struct{} - -var _ printer.Printer = &packagePrinter{} - -const ( - packagePrefixFormat = "Package %q:" - logDepth = 2 -) - -func (p *packagePrinter) PrintPackage(pkg *pkg.Pkg, _ bool) { - p.printfDepth(logDepth, packagePrefixFormat, pkg.DisplayPath) -} - -func (p *packagePrinter) Printf(format string, args ...any) { - p.printfDepth(logDepth, format, args...) -} - -func (p *packagePrinter) printfDepth(depth int, format string, args ...any) { - klog.InfofDepth(depth, format, args...) -} - -func (p *packagePrinter) OptPrintf(opt *printer.Options, format string, args ...any) { - if opt == nil { - p.Printf(format, args...) - return - } - var prefix string - switch { - case opt.PkgDisplayName != "": - prefix = fmt.Sprintf(packagePrefixFormat, opt.PkgDisplayName) - case !opt.PkgDisplayPath.Empty(): - prefix = fmt.Sprintf(packagePrefixFormat, string(opt.PkgDisplayPath)) - case !opt.PkgPath.Empty(): - prefix = fmt.Sprintf(packagePrefixFormat, string(opt.PkgPath)) - } - p.printfDepth(logDepth, prefix+format, args...) -} - -func (p *packagePrinter) OutStream() io.Writer { - return os.Stdout -} - -func (p *packagePrinter) ErrStream() io.Writer { - return os.Stderr + return rr.Execute(printer.WithContext(ctx, printer.NewKlogPrinter())) } diff --git a/pkg/lib/kptops/render_test.go b/pkg/lib/kptops/render_test.go index 394c2cf906..e46502a172 100644 --- a/pkg/lib/kptops/render_test.go +++ b/pkg/lib/kptops/render_test.go @@ -163,7 +163,7 @@ func TestPackagePrinter(t *testing.T) { func TestPackagePrinterStub(t *testing.T) { t.Run("PrintPackage stub", func(t *testing.T) { - p := &packagePrinter{} + p := printer.NewKlogPrinter() testPkg := &pkg.Pkg{ DisplayPath: "test/path", } @@ -178,7 +178,7 @@ func TestPackagePrinterStub(t *testing.T) { }) t.Run("Printf stub", func(t *testing.T) { - p := &packagePrinter{} + p := printer.NewKlogPrinter() assert.NotPanics(t, func() { p.Printf("test message") @@ -190,7 +190,7 @@ func TestPackagePrinterStub(t *testing.T) { }) t.Run("OptPrintf stub with nil options", func(t *testing.T) { - p := &packagePrinter{} + p := printer.NewKlogPrinter() assert.NotPanics(t, func() { p.OptPrintf(nil, "test message") @@ -198,7 +198,7 @@ func TestPackagePrinterStub(t *testing.T) { }) t.Run("OptPrintf stub with options", func(t *testing.T) { - p := &packagePrinter{} + p := printer.NewKlogPrinter() opt := printer.NewOpt().DisplayName("my-package") assert.NotPanics(t, func() { @@ -207,7 +207,7 @@ func TestPackagePrinterStub(t *testing.T) { }) t.Run("OutStream stub", func(t *testing.T) { - p := &packagePrinter{} + p := printer.NewKlogPrinter() stream := p.OutStream() assert.NotNil(t, stream) @@ -215,7 +215,7 @@ func TestPackagePrinterStub(t *testing.T) { }) t.Run("ErrStream stub", func(t *testing.T) { - p := &packagePrinter{} + p := printer.NewKlogPrinter() stream := p.ErrStream() assert.NotNil(t, stream) @@ -236,7 +236,7 @@ func TestPrinterLoggingDepth(t *testing.T) { } expectedFile := filepath.Base(filename) - p := &packagePrinter{} + p := printer.NewKlogPrinter() tests := []struct { name string diff --git a/pkg/printer/fake/fake.go b/pkg/printer/fake/fake.go index 0821398061..105b7ec374 100644 --- a/pkg/printer/fake/fake.go +++ b/pkg/printer/fake/fake.go @@ -17,6 +17,7 @@ package fake import ( "context" "io" + "time" "github.com/kptdev/kpt/pkg/lib/pkg" "github.com/kptdev/kpt/pkg/printer" @@ -29,6 +30,24 @@ type Printer struct { errStream io.Writer } +func (np *Printer) WithField(string, string) printer.Printer { return np } + +func (np *Printer) WithFields(printer.ContextualFields) printer.Printer { return np } + +func (np *Printer) WithPackage(string) printer.Printer { return np } + +func (np *Printer) WithFunction(string, string) printer.Printer { return np } + +func (np *Printer) PrintRunning(string, int) {} + +func (np *Printer) PrintPass(string, time.Duration) {} + +func (np *Printer) PrintFail(string, time.Duration, error) {} + +func (np *Printer) PrintResult(string, string, string) {} + +func (np *Printer) PrintSummary(int, int, time.Duration) {} + func (np *Printer) PrintPackage(*pkg.Pkg, bool) {} func (np *Printer) OptPrintf(*printer.Options, string, ...any) {} diff --git a/pkg/printer/printer.go b/pkg/printer/printer.go index 07e3d8e62c..1524dee7ed 100644 --- a/pkg/printer/printer.go +++ b/pkg/printer/printer.go @@ -12,7 +12,7 @@ // See the License for the specific language governing permissions and // limitations under the License. -// Package printer defines utilities to display kpt CLI output. +// Package printer defines utilities to display kpt CLI and Porch output. package printer import ( @@ -20,9 +20,15 @@ import ( "fmt" "io" "os" + "sort" + "strconv" + "strings" + "sync" + "time" kptfilev1 "github.com/kptdev/kpt/api/kptfile/v1" "github.com/kptdev/kpt/pkg/lib/pkg" + "k8s.io/klog/v2" ) // TruncateOutput defines should output be truncated @@ -30,15 +36,33 @@ var TruncateOutput bool const ( packagePrefixFormat = "Package %q:" + defaultLogDepth = 2 ) -// Printer defines capabilities to display content in kpt CLI. -// The main intention, at the moment, is to abstract away printing -// output in the CLI so that we can evolve the kpt CLI UX. +// ContextualFields holds key-value metadata pairs (e.g. image, tag, package, requestID, user). +type ContextualFields map[string]string + +// Printer defines capabilities to display content in kpt CLI and Porch. type Printer interface { + // Contextual scoping methods (returns a child Printer with updated key-value fields) + WithField(key, value string) Printer + WithFields(fields ContextualFields) Printer + WithPackage(pkgName string) Printer + WithFunction(image, tag string) Printer + + // Structured lifecycle events + PrintRunning(fnRef string, resourceCount int) + PrintPass(fnRef string, duration time.Duration) + PrintFail(fnRef string, duration time.Duration, err error) + PrintResult(severity, msg string, targetRef string) + PrintSummary(executedFnCnt, pkgCnt int, totalTime time.Duration) + + // Legacy printing methods PrintPackage(pkg *pkg.Pkg, leadingNewline bool) Printf(format string, args ...any) OptPrintf(opt *Options, format string, args ...any) + + // Stream accessors OutStream() io.Writer ErrStream() io.Writer } @@ -77,7 +101,7 @@ func (opt *Options) DisplayName(name string) *Options { return opt } -// New returns an instance of Printer. +// New returns an instance of stream-based Printer for kpt CLI. func New(outStream, errStream io.Writer) Printer { if outStream == nil { outStream = os.Stdout @@ -88,79 +112,274 @@ func New(outStream, errStream io.Writer) Printer { return &printer{ outStream: outStream, errStream: errStream, + fields: make(ContextualFields), } } -// printer implements default Printer to be used in kpt codebase. +// NewKlogPrinter returns a Printer that writes logs using klog.InfofDepth. +func NewKlogPrinter() Printer { + return &printer{ + outStream: os.Stdout, + errStream: os.Stderr, + logFn: func(depth int, format string, args ...any) { + klog.InfofDepth(depth, format, args...) + }, + fields: make(ContextualFields), + } +} + +// NewWithLogFunc returns a Printer that delegates log printing to a custom log function. +func NewWithLogFunc(logFn func(depth int, format string, args ...any)) Printer { + return &printer{ + outStream: os.Stdout, + errStream: os.Stderr, + logFn: logFn, + fields: make(ContextualFields), + } +} + +// printer implements Printer for kpt CLI and Porch. type printer struct { + mu sync.RWMutex outStream io.Writer errStream io.Writer + logFn func(depth int, format string, args ...any) + fields ContextualFields } -// The key type is unexported to prevent collisions with context keys defined in -// other packages. -type contextKey int +// clone creates a copy of the printer with cloned contextual fields. +func (pr *printer) clone() *printer { + pr.mu.RLock() + defer pr.mu.RUnlock() -// printerKey is the context key for the printer. Its value of zero is -// arbitrary. If this package defined other context keys, they would have -// different integer values. -const printerKey contextKey = 0 + newFields := make(ContextualFields, len(pr.fields)) + for k, v := range pr.fields { + newFields[k] = v + } + + return &printer{ + outStream: pr.outStream, + errStream: pr.errStream, + logFn: pr.logFn, + fields: newFields, + } +} -// OutStream returns the StdOut stream, this can be used by callers to print -// command output to stdout, do not print error/debug logs to this stream +// WithField returns a child Printer with the specified key-value field attached. +func (pr *printer) WithField(key, value string) Printer { + child := pr.clone() + if value != "" { + child.fields[key] = value + } else { + delete(child.fields, key) + } + return child +} + +// WithFields returns a child Printer with the provided key-value fields attached. +func (pr *printer) WithFields(fields ContextualFields) Printer { + child := pr.clone() + for k, v := range fields { + if v != "" { + child.fields[k] = v + } else { + delete(child.fields, k) + } + } + return child +} + +// WithPackage returns a child Printer with the package field attached. +func (pr *printer) WithPackage(pkgName string) Printer { + return pr.WithField("package", pkgName) +} + +// WithFunction returns a child Printer with image and tag fields attached. +func (pr *printer) WithFunction(image, tag string) Printer { + p := pr.WithField("image", image) + if tag != "" { + p = p.WithField("tag", tag) + } + return p +} + +// OutStream returns the StdOut stream. func (pr *printer) OutStream() io.Writer { return pr.outStream } -// ErrStream returns the StdErr stream, this can be used by callers to print -// command output to stderr, print only error/debug/info logs to this stream +// ErrStream returns the StdErr stream. func (pr *printer) ErrStream() io.Writer { return pr.errStream } -// PrintPackage prints the package display path to stderr +// formatFields returns sorted, formatted key-value pairs (e.g. image="set-labels" tag="latest"). +func (pr *printer) formatFields(extraFields ...ContextualFields) string { + pr.mu.RLock() + combined := make(ContextualFields, len(pr.fields)) + for k, v := range pr.fields { + combined[k] = v + } + pr.mu.RUnlock() + + for _, ef := range extraFields { + for k, v := range ef { + if v != "" { + combined[k] = v + } + } + } + + if len(combined) == 0 { + return "" + } + + keys := make([]string, 0, len(combined)) + for k := range combined { + keys = append(keys, k) + } + sort.Strings(keys) + + var sb strings.Builder + for i, k := range keys { + if i > 0 { + sb.WriteString(" ") + } + sb.WriteString(fmt.Sprintf("%s=%s", k, strconv.Quote(combined[k]))) + } + return sb.String() +} + +func (pr *printer) printInternal(format string, args ...any) { + if pr.logFn != nil { + pr.logFn(defaultLogDepth+1, format, args...) + } else { + fmt.Fprintf(pr.errStream, format, args...) + } +} + +// PrintRunning outputs a [RUNNING] lifecycle event. +func (pr *printer) PrintRunning(fnRef string, resourceCount int) { + extra := ContextualFields{} + if resourceCount > 0 { + extra["resourceCount"] = strconv.Itoa(resourceCount) + } + attrStr := pr.formatFields(extra) + + if attrStr != "" { + pr.printInternal("[RUNNING] %s\n", attrStr) + } else if resourceCount > 0 { + pr.printInternal("[RUNNING] %s on %d resource(s)\n", strconv.Quote(fnRef), resourceCount) + } else { + pr.printInternal("[RUNNING] %s\n", strconv.Quote(fnRef)) + } +} + +// PrintPass outputs a [PASS] lifecycle event. +func (pr *printer) PrintPass(fnRef string, duration time.Duration) { + extra := ContextualFields{} + if duration > 0 { + extra["time"] = duration.Truncate(time.Millisecond).String() + } + attrStr := pr.formatFields(extra) + + if attrStr != "" { + pr.printInternal("[PASS] %s\n", attrStr) + } else { + pr.printInternal("[PASS] %q in %v\n", fnRef, duration.Truncate(time.Millisecond)) + } +} + +// PrintFail outputs a [FAIL] lifecycle event. +func (pr *printer) PrintFail(fnRef string, duration time.Duration, err error) { + extra := ContextualFields{} + if duration > 0 { + extra["time"] = duration.Truncate(time.Millisecond).String() + } + if err != nil { + extra["error"] = err.Error() + } + attrStr := pr.formatFields(extra) + + if attrStr != "" { + pr.printInternal("[FAIL] %s\n", attrStr) + } else { + pr.printInternal("[FAIL] %q in %v\n", fnRef, duration.Truncate(time.Millisecond)) + } +} + +// PrintResult outputs a structured result item line. +func (pr *printer) PrintResult(severity, msg string, targetRef string) { + if targetRef != "" { + pr.printInternal(" [%s] %s: %s\n", severity, targetRef, msg) + } else { + pr.printInternal(" [%s]: %s\n", severity, msg) + } +} + +// PrintSummary outputs a pipeline execution summary line. +func (pr *printer) PrintSummary(executedFnCnt, pkgCnt int, totalTime time.Duration) { + extra := ContextualFields{} + if totalTime > 0 { + extra["time"] = totalTime.Truncate(time.Millisecond).String() + } + attrStr := pr.formatFields(extra) + + if attrStr != "" { + pr.printInternal("Successfully executed %d function(s) in %d package(s) %s\n", executedFnCnt, pkgCnt, attrStr) + } else { + pr.printInternal("Successfully executed %d function(s) in %d package(s).\n", executedFnCnt, pkgCnt) + } +} + +// PrintPackage prints the package display path. func (pr *printer) PrintPackage(p *pkg.Pkg, leadingNewline bool) { - if leadingNewline { + if leadingNewline && pr.logFn == nil { fmt.Fprint(pr.errStream, "\n") } - fmt.Fprintf(pr.errStream, "Package %q:\n", p.DisplayPath) + if pr.logFn != nil { + pr.logFn(defaultLogDepth+1, packagePrefixFormat, p.DisplayPath) + } else { + fmt.Fprintf(pr.errStream, "Package %q:\n", p.DisplayPath) + } } // Printf is the wrapper over fmt.Printf that displays the output. -// this will print messages to stderr stream func (pr *printer) Printf(format string, args ...any) { - fmt.Fprintf(pr.errStream, format, args...) + pr.printInternal(format, args...) } -// OptPrintf is the wrapper over fmt.Printf that displays the output according -// to the opt, this will print messages to stderr stream -// https://mehulkar.com/blog/2017/11/stdout-vs-stderr/ +// OptPrintf is the wrapper over fmt.Printf that displays output according to the options. func (pr *printer) OptPrintf(opt *Options, format string, args ...any) { if opt == nil { - fmt.Fprintf(pr.errStream, format, args...) + pr.printInternal(format, args...) return } - o := pr.errStream + + var prefix string switch { case opt.PkgDisplayName != "": - format = fmt.Sprintf(packagePrefixFormat, opt.PkgDisplayName) + format + prefix = fmt.Sprintf(packagePrefixFormat, opt.PkgDisplayName) case !opt.PkgDisplayPath.Empty(): - format = fmt.Sprintf(packagePrefixFormat, string(opt.PkgDisplayPath)) + format + prefix = fmt.Sprintf(packagePrefixFormat, string(opt.PkgDisplayPath)) case !opt.PkgPath.Empty(): - // try to print relative path of the pkg if we can else use abs path relPath, err := opt.PkgPath.RelativePath() if err != nil { relPath = string(opt.PkgPath) } - format = fmt.Sprintf(packagePrefixFormat, relPath) + format + prefix = fmt.Sprintf(packagePrefixFormat, relPath) } - fmt.Fprintf(o, format, args...) + + pr.printInternal(prefix+format, args...) } -// Helper functions to set and retrieve printer instance from a context. -// Defining them here avoids the context key collision. +// Context keys and helper functions -// FromContext returns printer instance associated with the context. +type contextKey int + +const printerKey contextKey = 0 + +// FromContextOrDie returns the Printer instance associated with the context. func FromContextOrDie(ctx context.Context) Printer { pr, ok := ctx.Value(printerKey).(Printer) if ok { @@ -169,8 +388,8 @@ func FromContextOrDie(ctx context.Context) Printer { panic("printer missing in context") } -// WithContext creates new context from the given parent context -// by setting the printer instance. +// WithContext creates a new context setting the printer instance. func WithContext(ctx context.Context, pr Printer) context.Context { return context.WithValue(ctx, printerKey, pr) } + diff --git a/pkg/printer/printer_test.go b/pkg/printer/printer_test.go index a3fee4e8f9..cb64233fa8 100644 --- a/pkg/printer/printer_test.go +++ b/pkg/printer/printer_test.go @@ -102,3 +102,64 @@ func TestPrintPackage_WithoutLeadingNewline(t *testing.T) { t.Errorf("Expected %q, got %q", expected, buf.String()) } } + +func TestPrinter_ContextualFieldsAndEvents(t *testing.T) { + t.Run("WithField and WithFields scoping", func(t *testing.T) { + var buf bytes.Buffer + pr := New(&buf, &buf) + + p1 := pr.WithField("package", "wordpress") + p2 := p1.WithFunction("set-labels", "latest").WithFields(ContextualFields{ + "requestID": "req-123", + "user": "admin", + }) + + p2.PrintRunning("set-labels", 2) + got := buf.String() + expected := "[RUNNING] image=\"set-labels\" package=\"wordpress\" requestID=\"req-123\" resourceCount=\"2\" tag=\"latest\" user=\"admin\"\n" + if got != expected { + t.Errorf("Expected %q, got %q", expected, got) + } + + // Verify original printer p1 is unmodified + buf.Reset() + p1.PrintRunning("set-labels", 0) + gotP1 := buf.String() + expectedP1 := "[RUNNING] package=\"wordpress\"\n" + if gotP1 != expectedP1 { + t.Errorf("Expected %q, got %q", expectedP1, gotP1) + } + }) + + t.Run("PrintPass and PrintFail", func(t *testing.T) { + var buf bytes.Buffer + pr := New(&buf, &buf).WithFunction("kubeconform", "latest").WithPackage("wordpress") + + pr.PrintPass("kubeconform", 250*1000*1000) // 250ms + gotPass := buf.String() + expectedPass := "[PASS] image=\"kubeconform\" package=\"wordpress\" tag=\"latest\" time=\"250ms\"\n" + if gotPass != expectedPass { + t.Errorf("Expected %q, got %q", expectedPass, gotPass) + } + + buf.Reset() + pr.PrintFail("kubeconform", 100*1000*1000, nil) + gotFail := buf.String() + expectedFail := "[FAIL] image=\"kubeconform\" package=\"wordpress\" tag=\"latest\" time=\"100ms\"\n" + if gotFail != expectedFail { + t.Errorf("Expected %q, got %q", expectedFail, gotFail) + } + }) + + t.Run("PrintSummary", func(t *testing.T) { + var buf bytes.Buffer + pr := New(&buf, &buf).WithField("user", "porch-controller") + + pr.PrintSummary(4, 2, 1170*1000*1000) + gotSummary := buf.String() + expectedSummary := "Successfully executed 4 function(s) in 2 package(s) time=\"1.17s\" user=\"porch-controller\"\n" + if gotSummary != expectedSummary { + t.Errorf("Expected %q, got %q", expectedSummary, gotSummary) + } + }) +}