From 62766dfaa809dc313959d1a8a738307f51fec177 Mon Sep 17 00:00:00 2001 From: Jens Topp Date: Fri, 26 Jun 2026 18:54:25 +0200 Subject: [PATCH] feat: add --log level and keep diagnostics off stdout The client used to print diagnostic logs and errors to stdout, mixing them into command output and breaking the json/yaml formats. That is fixed, and how much the client reports is now configurable. - New --log flag sets diagnostic verbosity: debug, warn (default), or none. - Diagnostics and errors now go to stderr; stdout carries only command output, so piping and -f json|yaml stay clean. - At the default warn level, warnings are collected into a short summary at the end of the run rather than interrupting output. - Terminal output is color-coded (errors, warnings, file transfers, status); color turns off automatically when output is piped or redirected, or with -no-color. - Ctrl-C now stops a running command cleanly. The -v flag is unchanged. Signed-off-by: Jens Topp --- .golangci.yml | 12 ++ CONTRIBUTING.md | 18 +++ cmds/dutctl/clilog.go | 222 +++++++++++++++++++++++++++++++++++ cmds/dutctl/clilog_test.go | 128 ++++++++++++++++++++ cmds/dutctl/dutctl.go | 94 +++++++++++---- cmds/dutctl/rpc.go | 68 ++++++++--- cmds/dutctl/term.go | 30 +++++ cmds/dutctl/term_test.go | 30 +++++ internal/output/json.go | 4 +- internal/output/oneline.go | 7 ++ internal/output/output.go | 11 ++ internal/output/text.go | 106 ++++++++++++----- internal/output/text_test.go | 103 +++++++++++++++- internal/output/yaml.go | 6 +- internal/style/style.go | 39 ++++++ 15 files changed, 796 insertions(+), 82 deletions(-) create mode 100644 cmds/dutctl/clilog.go create mode 100644 cmds/dutctl/clilog_test.go create mode 100644 cmds/dutctl/term.go create mode 100644 cmds/dutctl/term_test.go create mode 100644 internal/style/style.go diff --git a/.golangci.yml b/.golangci.yml index 7d64101c..ac2aa349 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -124,6 +124,18 @@ linters: - zerologlint settings: + forbidigo: + forbid: + # Re-add forbidigo's defaults (defining `forbid` replaces them). + - pattern: '^(fmt\.Print(|f|ln)|print|println)$' + msg: do not print to stdout directly; use fmt.Fprint with an explicit writer, the output formatter, or slog + - pattern: '^spew\.(ConfigState\.)?Dump$' + msg: remove debug spew.Dump calls before committing + # Only slog.Debug and slog.Warn are sanctioned; other levels map into the + # client's two-channel logging model. + - pattern: '^slog\.(Info|Error|Log|LogAttrs|DebugContext|InfoContext|WarnContext|ErrorContext)$' + msg: use slog.Debug or slog.Warn only + funcorder: # Checks if the exported methods of a structure are placed before the non-exported ones. # Default: true diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 20354540..e2ff2f25 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -134,6 +134,24 @@ We recommend setting up your editor to run golangci-lint automatically. Most pop - **GoLand**: Install the Golangci-lint plugin - **Vim/Neovim**: Configure with ALE or similar linting engines +### Logging + +The `dutctl` client keeps diagnostic logging separate from command output: + +- **stdout** carries results and agent/module output (the `output.Formatter`). Never log to stdout. +- **stderr** carries client diagnostics via the standard `log/slog` package. + +Use only two levels: + +- `slog.Debug` — internal trace; hidden unless the user passes `--log debug`. +- `slog.Warn` — non-fatal anomalies. By default (`--log warn`) warnings are collected and printed as a short summary when the command finishes, so they never interrupt streaming output. + +Other slog entry points (`slog.Info`, `slog.Error`, `slog.Log`, the `*Context` variants) are rejected by `forbidigo`. The handler still maps any level by severity (`>= Warn` → warn, else debug), but write `Debug`/`Warn` in code. + +Errors that should stop the command are **returned**, not logged — they bubble up to a single exit point and are rendered through the formatter (format-aware, on stderr). There is intentionally no error log level. + +The handler and the `--log` flag (`debug|warn|none`, default `warn`) live in [`cmds/dutctl/clilog.go`](cmds/dutctl/clilog.go). + ### Documentation Style Guide - Use Markdown for documentation diff --git a/cmds/dutctl/clilog.go b/cmds/dutctl/clilog.go new file mode 100644 index 00000000..e758b5a2 --- /dev/null +++ b/cmds/dutctl/clilog.go @@ -0,0 +1,222 @@ +// Copyright 2025 Blindspot Software +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +package main + +import ( + "context" + "errors" + "flag" + "fmt" + "io" + "log/slog" + "strings" + "sync" + + "github.com/BlindspotSoftware/dutctl/internal/style" +) + +// logMode controls how diagnostic log records are handled. It is derived from +// the --log flag and implements flag.Value, so an invalid --log value is +// rejected during flag parsing (flag.ExitOnError prints the error plus usage +// and exits) rather than being validated separately. +type logMode int + +// Ensure implementing the flag.Value interface. +var _ flag.Value = (*logMode)(nil) + +const ( + // logModeNone drops all diagnostics. + logModeNone logMode = iota + // logModeWarn drops debug records and accumulates warnings into a summary + // that is flushed on termination (the default). + logModeWarn + // logModeDebug writes every record live to stderr in temporal order. + logModeDebug +) + +// parseLogMode maps a --log flag value to a logMode. Unknown values are +// rejected. The message is intentionally bare ("must be ...") because the flag +// package wraps it as `invalid value %q for flag -log: `. +func parseLogMode(s string) (logMode, error) { + switch s { + case "none": + return logModeNone, nil + case "warn": + return logModeWarn, nil + case "debug": + return logModeDebug, nil + default: + return 0, errors.New("must be debug, warn, or none") + } +} + +// String renders the mode and provides the flag's default display. +func (m *logMode) String() string { + switch *m { + case logModeNone: + return "none" + case logModeDebug: + return "debug" + default: + return "warn" + } +} + +// Set parses and stores the flag value, returning an error for unknown values. +func (m *logMode) Set(s string) error { + mode, err := parseLogMode(s) + if err != nil { + return err + } + + *m = mode + + return nil +} + +// cliHandler is a slog.Handler tailored for an interactive CLI. It writes +// diagnostics to stderr only, and dispatches purely on the record's level so +// that any slog entry point (Debug/Info/Warn/Error/Log/...) is mapped into a +// two-channel model: everything < Warn is "debug tier", everything >= Warn is +// "warn tier". +// +// In warn mode, warn-tier records are accumulated and flushed as a summary on +// termination so they never interrupt command output. In debug mode every +// record is written live. +type cliHandler struct { + w io.Writer + mode logMode + useColor bool + mu *sync.Mutex // shared across WithAttrs/WithGroup copies + buf *[]string // accumulated warning lines, shared via pointer + attrs []slog.Attr + groups []string +} + +// Ensure implementing the slog.Handler interface. +var _ slog.Handler = (*cliHandler)(nil) + +// newCLIHandler creates a cliHandler writing to w. +func newCLIHandler(w io.Writer, mode logMode, useColor bool) *cliHandler { + return &cliHandler{ + w: w, + mode: mode, + useColor: useColor, + mu: &sync.Mutex{}, + buf: &[]string{}, + } +} + +// Enabled reports whether a record at the given level should be handled. +func (h *cliHandler) Enabled(_ context.Context, level slog.Level) bool { + switch h.mode { + case logModeNone: + return false + case logModeWarn: + return level >= slog.LevelWarn // drops Debug & Info (everything below Warn) + default: // logModeDebug + return true + } +} + +// Handle writes (debug mode) or buffers (warn mode) a record. +func (h *cliHandler) Handle(_ context.Context, rec slog.Record) error { + line := h.render(rec) + + h.mu.Lock() + defer h.mu.Unlock() + + if h.mode == logModeDebug { + fmt.Fprintln(h.w, line) // live, temporal order + + return nil + } + + // logModeWarn: only warn-tier (>= Warn) records reach here; Enabled gates the rest. + *h.buf = append(*h.buf, line) + + return nil +} + +// WithAttrs returns a copy with attrs appended, sharing the buffer and mutex so +// warning accumulation stays global. +func (h *cliHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + clone := *h + clone.attrs = append(append([]slog.Attr{}, h.attrs...), attrs...) + + return &clone +} + +// WithGroup returns a copy that prefixes subsequent attribute keys with name. +func (h *cliHandler) WithGroup(name string) slog.Handler { + if name == "" { + return h + } + + clone := *h + clone.groups = append(append([]string{}, h.groups...), name) + + return &clone +} + +// render formats a record as a single line: "[LEVEL ]msg key=value ...". The +// level prefix is only added in debug mode, where records of different levels +// are interleaved; in the warn summary the lines sit under a header so the +// prefix is redundant. +func (h *cliHandler) render(rec slog.Record) string { + var builder strings.Builder + + if h.mode == logModeDebug { + builder.WriteString(rec.Level.String()) + builder.WriteByte(' ') + } + + builder.WriteString(rec.Message) + + prefix := "" + if len(h.groups) > 0 { + prefix = strings.Join(h.groups, ".") + "." + } + + writeAttr := func(a slog.Attr) { + builder.WriteByte(' ') + builder.WriteString(prefix) + builder.WriteString(a.Key) + builder.WriteByte('=') + builder.WriteString(a.Value.String()) + } + + for _, a := range h.attrs { + writeAttr(a) + } + + rec.Attrs(func(a slog.Attr) bool { + writeAttr(a) + + return true + }) + + return builder.String() +} + +// Flush writes the accumulated warning summary (warn mode) and clears the +// buffer. It is safe to call in any mode and when no warnings were recorded. +func (h *cliHandler) Flush() { + h.mu.Lock() + defer h.mu.Unlock() + + if len(*h.buf) == 0 { + return + } + + header := fmt.Sprintf("%s %d warning(s) during run:", style.MarkerWarning, len(*h.buf)) + fmt.Fprintln(h.w, style.Colorize(h.useColor, style.Yellow, header)) + + for _, line := range *h.buf { + fmt.Fprintf(h.w, " - %s\n", line) + } + + *h.buf = (*h.buf)[:0] +} diff --git a/cmds/dutctl/clilog_test.go b/cmds/dutctl/clilog_test.go new file mode 100644 index 00000000..a5df4c89 --- /dev/null +++ b/cmds/dutctl/clilog_test.go @@ -0,0 +1,128 @@ +// Copyright 2025 Blindspot Software +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +package main + +import ( + "bytes" + "log/slog" + "strings" + "testing" +) + +func TestParseLogMode(t *testing.T) { + tests := []struct { + in string + want logMode + wantErr bool + }{ + {"debug", logModeDebug, false}, + {"warn", logModeWarn, false}, + {"none", logModeNone, false}, + {"", 0, true}, + {"info", 0, true}, + {"bogus", 0, true}, + } + + for _, tt := range tests { + got, err := parseLogMode(tt.in) + if tt.wantErr { + if err == nil { + t.Errorf("parseLogMode(%q): want error, got nil", tt.in) + } + + continue + } + + if err != nil { + t.Errorf("parseLogMode(%q): unexpected error: %v", tt.in, err) + } + + if got != tt.want { + t.Errorf("parseLogMode(%q) = %v, want %v", tt.in, got, tt.want) + } + } +} + +// newTestLogger returns a logger backed by a cliHandler in the given mode, +// writing (colourless) to the returned buffer. +func newTestLogger(mode logMode) (*slog.Logger, *cliHandler, *bytes.Buffer) { + var buf bytes.Buffer + + h := newCLIHandler(&buf, mode, false) + + return slog.New(h), h, &buf +} + +func TestCLIHandler_WarnMode_BuffersUntilFlush(t *testing.T) { + logger, handler, buf := newTestLogger(logModeWarn) + + logger.Debug("d1") // dropped (debug tier) + logger.Info("i1") // dropped (Info < Warn) + logger.Warn("w1", "k", "v") // buffered (warn tier) + logger.Error("e1") // buffered (Error >= Warn → warn tier) + + if buf.Len() != 0 { + t.Fatalf("warn mode wrote before flush:\n%s", buf.String()) + } + + handler.Flush() + + out := buf.String() + if !strings.Contains(out, "2 warning(s) during run:") { + t.Errorf("missing summary header, got:\n%s", out) + } + + for _, want := range []string{"- w1 k=v", "- e1"} { + if !strings.Contains(out, want) { + t.Errorf("summary missing %q, got:\n%s", want, out) + } + } + + if strings.Contains(out, "d1") || strings.Contains(out, "i1") { + t.Errorf("debug/info leaked into warn summary:\n%s", out) + } +} + +func TestCLIHandler_DebugMode_WritesLive(t *testing.T) { + logger, handler, buf := newTestLogger(logModeDebug) + + logger.Debug("d1") + logger.Warn("w1") + + out := buf.String() + if !strings.Contains(out, "DEBUG d1") || !strings.Contains(out, "WARN w1") { + t.Errorf("debug mode did not write live, got:\n%s", out) + } + + before := buf.Len() + handler.Flush() // nothing buffered in debug mode + + if buf.Len() != before { + t.Errorf("Flush wrote in debug mode: %q", buf.String()[before:]) + } +} + +func TestCLIHandler_NoneMode_Silent(t *testing.T) { + logger, handler, buf := newTestLogger(logModeNone) + + logger.Debug("d1") + logger.Warn("w1") + logger.Error("e1") + handler.Flush() + + if buf.Len() != 0 { + t.Errorf("none mode produced output:\n%s", buf.String()) + } +} + +func TestCLIHandler_FlushNoWarnings_NoOutput(t *testing.T) { + _, handler, buf := newTestLogger(logModeWarn) + + handler.Flush() + + if buf.Len() != 0 { + t.Errorf("Flush with no warnings produced output:\n%s", buf.String()) + } +} diff --git a/cmds/dutctl/dutctl.go b/cmds/dutctl/dutctl.go index 34d4d017..d9dc8911 100644 --- a/cmds/dutctl/dutctl.go +++ b/cmds/dutctl/dutctl.go @@ -11,7 +11,7 @@ import ( "flag" "fmt" "io" - "log" + "log/slog" "net/http" "os" @@ -51,13 +51,15 @@ option to release a lock held by another user. ` +// Usage strings for the command-line flags, shown in the OPTIONS section of `dutctl -h`. const ( - serverAddrInfo = `Address and port of the dutagent to connect to in the format: address:port` - outputFormatInfo = `Output format, text|json|yaml|oneline, default is text` - verboseInfo = `Verbose output` - noColorInfo = `Disable colored output` - userInfo = `User Identity of the user of the device, defaults to @` - forceInfo = `Force unlock a device locked by another user` + serverAddrUsage = `Address and port of the dutagent to connect to in the format: address:port` + outputFormatUsage = `Output format, text|json|yaml|oneline, default is text` + verboseUsage = `Annotate output with connection/RPC context (metadata)` + noColorUsage = `Disable colored output` + userUsage = `User Identity of the user of the device, defaults to @` + forceUsage = `Force unlock a device locked by another user` + logUsage = `Client-side diagnostic logging (on stderr), debug|warn|none, default is warn` ) func newApp(stdin io.Reader, stdout, stderr io.Writer, exitFunc func(int), args []string) *application { @@ -80,24 +82,37 @@ func newApp(stdin io.Reader, stdout, stderr io.Writer, exitFunc func(int), args app.printFlagDefaults() } // Flags - fs.StringVar(&app.serverAddr, "s", "localhost:1024", serverAddrInfo) - fs.StringVar(&app.outputFormat, "f", "", outputFormatInfo) - fs.BoolVar(&app.verbose, "v", false, verboseInfo) - fs.BoolVar(&app.noColor, "no-color", false, noColorInfo) - fs.StringVar(&app.user, "u", lock.DefaultUser(), userInfo) - fs.BoolVar(&app.force, "force", false, forceInfo) + fs.StringVar(&app.serverAddr, "s", "localhost:1024", serverAddrUsage) + fs.StringVar(&app.outputFormat, "f", "", outputFormatUsage) + fs.BoolVar(&app.verbose, "v", false, verboseUsage) + fs.BoolVar(&app.noColor, "no-color", false, noColorUsage) + fs.StringVar(&app.user, "u", lock.DefaultUser(), userUsage) + fs.BoolVar(&app.force, "force", false, forceUsage) + + mode := logModeWarn + fs.Var(&mode, "log", logUsage) //nolint:errcheck // flag.Parse always returns no error because of flag.ExitOnError fs.Parse(args[1:]) app.args = fs.Args() + // Setup diagnostic logging. The handler writes to stderr only and is + // installed as the process default so any package can log via package-level + // slog. An invalid --log value was already rejected by fs.Parse above. + // + // Color is suppressed unless -no-color is unset AND the target stream is a + // terminal, so redirected/piped output stays free of ANSI escapes. The log + // handler is gated on stderr; the formatter's content on stdout. + app.logHandler = newCLIHandler(stderr, mode, !app.noColor && isTerminal(stderr)) + slog.SetDefault(slog.New(app.logHandler)) + // Setup output formatter app.formatter = output.New(output.Config{ Stdout: stdout, Stderr: stderr, Format: app.outputFormat, Verbose: app.verbose, - NoColor: app.noColor, + NoColor: app.noColor || !isTerminal(stdout), }) return &app @@ -119,8 +134,14 @@ type application struct { args []string printFlagDefaults func() + // runtime services rpcClient dutctlv1connect.DeviceServiceClient formatter output.Formatter + // logHandler is retained only so exit can call Flush: diagnostics are emitted + // via package-level slog (this handler is the process default), but the + // buffered warning summary must be flushed explicitly and Flush is not part + // of the slog.Handler interface reachable through slog.Default(). + logHandler *cliHandler } func (app *application) setupRPCClient() { @@ -151,10 +172,12 @@ func newInsecureClient() *http.Client { var errInvalidCmdline = fmt.Errorf("invalid command line") +// exitInterrupted is the conventional exit code for termination by a signal +// such as SIGINT (128 + signal number 2). +const exitInterrupted = 130 + // start is the entry point of the application. func (app *application) start() { - log.SetOutput(app.stdout) - if len(app.args) == 0 { app.exit(errInvalidCmdline) } @@ -201,32 +224,51 @@ func (app *application) start() { app.exit(err) } -// exit terminates the application. If the provided error is not nil, it is printed to -// the standard error output. If printUsage is true, the usage information is printed additionally. +// exit terminates the application. Buffered diagnostics (the warning summary) +// are flushed first so they read as a trailing note, then any terminating +// status or error is rendered through the formatter as the final output. A nil +// error exits 0; an interrupt exits 130; any other error exits 1. func (app *application) exit(err error) { + if app.logHandler != nil { + app.logHandler.Flush() + } + if err == nil { - // Flush any buffered output before exiting if app.formatter != nil { _ = app.formatter.Flush() } app.exitFunc(0) + + return } - if err != nil { - log.Print(err) + if errors.Is(err, errInterrupted) { + app.formatter.WriteContent(output.Content{ + Type: output.TypeGeneral, + Data: "interrupted", + IsError: true, + }) + + _ = app.formatter.Flush() + app.exitFunc(exitInterrupted) + + return } + // Render the terminating error through the formatter (stderr, format-aware). + app.formatter.WriteContent(output.Content{ + Type: output.TypeGeneral, + Data: err.Error(), + IsError: true, + }) + if errors.Is(err, errInvalidCmdline) { fmt.Fprint(app.stderr, usageSynopsis) app.printFlagDefaults() } - // Flush any buffered output before exiting with error - if app.formatter != nil { - _ = app.formatter.Flush() - } - + _ = app.formatter.Flush() app.exitFunc(1) } diff --git a/cmds/dutctl/rpc.go b/cmds/dutctl/rpc.go index 13e3075c..a3c7893f 100644 --- a/cmds/dutctl/rpc.go +++ b/cmds/dutctl/rpc.go @@ -11,9 +11,11 @@ import ( "fmt" "io" "io/fs" - "log" + "log/slog" "os" + "os/signal" "strings" + "syscall" "time" "connectrpc.com/connect" @@ -23,6 +25,11 @@ import ( pb "github.com/BlindspotSoftware/dutctl/protobuf/gen/dutctl/v1" ) +// errInterrupted is returned by runRPC when the run is terminated by a signal +// (Ctrl-C) rather than by the agent or an error. exit() reports it as an +// "interrupted" status with exit code 130, not as a failure. +var errInterrupted = errors.New("interrupted") + func (app *application) listRPC() error { ctx := context.Background() req := connect.NewRequest(&pb.ListRequest{}) @@ -188,12 +195,18 @@ func (app *application) detailsRPC(device, command, keyword string) error { return nil } -//nolint:funlen,cyclop,gocognit +//nolint:funlen,cyclop,gocognit,maintidx // coordinates two streaming worker goroutines; inherently branchy func (app *application) runRPC(device, command string, cmdArgs []string) error { const numWorkers = 2 // The send and receive worker goroutines - runCtx, cancel := context.WithCancel(context.Background()) - defer cancel() + // appCtx is cancelled on SIGINT/SIGTERM so Ctrl-C terminates gracefully + // (running the normal teardown and flushing the warning summary) instead of + // killing the process. runCtx is the child the workers cancel on completion. + appCtx, cancelAppCtx := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) + defer cancelAppCtx() + + runCtx, cancelRunCtx := context.WithCancel(appCtx) + defer cancelRunCtx() errChan := make(chan error, numWorkers) @@ -225,23 +238,29 @@ func (app *application) runRPC(device, command string, cmdArgs []string) error { // Receive routine go func() { - defer cancel() + defer cancelRunCtx() for { select { case <-runCtx.Done(): - log.Println("Receive routine terminating: Run-Context cancelled") + slog.Debug("receive routine terminating", "reason", "run-context cancelled") return default: // Unblock select, continue with the forwarding logic. } res, err := stream.Receive() - if errors.Is(err, io.EOF) { - log.Println("Receive routine terminating: Stream closed by agent") + + switch { + case errors.Is(err, io.EOF): + slog.Debug("receive routine terminating", "reason", "stream closed by agent") + + return + case err != nil && (errors.Is(err, context.Canceled) || connect.CodeOf(err) == connect.CodeCanceled): + slog.Debug("receive routine terminating", "reason", "context cancelled") return - } else if err != nil { + case err != nil: errChan <- fmt.Errorf("receiving RPC message: %w", err) return @@ -271,11 +290,11 @@ func (app *application) runRPC(device, command string, cmdArgs []string) error { Metadata: metadata, }) case *pb.Console_Stdin: - log.Printf("Unexpected Console Stdin %q", string(consoleData.Stdin)) + slog.Warn("unexpected console stdin from agent", "data", string(consoleData.Stdin)) } case *pb.RunResponse_FileRequest: path := msg.FileRequest.GetPath() - log.Printf("File request for: %q\n", path) + slog.Debug("file requested by agent", "path", path) content, err := os.ReadFile(path) if err != nil { @@ -298,15 +317,17 @@ func (app *application) runRPC(device, command string, cmdArgs []string) error { return } - log.Printf("Sent file: %q\n", path) + app.formatter.WriteContent(output.Content{ + Type: output.TypeFileTransfer, + Data: output.FileTransfer{Direction: "sent", Path: path, Bytes: len(content)}, + Metadata: metadata, + }) case *pb.RunResponse_File: path := msg.File.GetPath() content := msg.File.GetContent() - log.Printf("Received file: %q\n", path) - if len(content) == 0 { - log.Println("Received empty file content") + slog.Warn("received empty file content", "path", path) } perm := 0600 @@ -318,8 +339,14 @@ func (app *application) runRPC(device, command string, cmdArgs []string) error { return } + app.formatter.WriteContent(output.Content{ + Type: output.TypeFileTransfer, + Data: output.FileTransfer{Direction: "received", Path: path, Bytes: len(content)}, + Metadata: metadata, + }) + default: - log.Printf("Unexpected message type %T", msg) + slog.Warn("unexpected message type", "type", fmt.Sprintf("%T", msg)) } } }() @@ -340,7 +367,7 @@ func (app *application) runRPC(device, command string, cmdArgs []string) error { for { select { case <-runCtx.Done(): - log.Println("Send routine terminating: Run-Context cancelled") + slog.Debug("send routine terminating", "reason", "run-context cancelled") return default: @@ -375,6 +402,13 @@ func (app *application) runRPC(device, command string, cmdArgs []string) error { // Wait for completion or error select { case <-runCtx.Done(): + // appCtx.Err() is non-nil only if a signal fired (the deferred + // cancelAppCtx has not run yet), distinguishing Ctrl-C from a normal + // stream-closed teardown. + if appCtx.Err() != nil { + return errInterrupted + } + return nil case err := <-errChan: return err diff --git a/cmds/dutctl/term.go b/cmds/dutctl/term.go new file mode 100644 index 00000000..9a15d62a --- /dev/null +++ b/cmds/dutctl/term.go @@ -0,0 +1,30 @@ +// Copyright 2025 Blindspot Software +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +package main + +import ( + "io" + "os" +) + +// isTerminal reports whether w is connected to an interactive terminal (TTY). +// +// Caveat of the stdlib: character devices such as /dev/null also +// report true. That is harmless here (nothing reads color written to +// /dev/null), while pipes and regular files — the cases that matter — correctly +// report false. +func isTerminal(w io.Writer) bool { + file, ok := w.(*os.File) + if !ok { + return false + } + + info, err := file.Stat() + if err != nil { + return false + } + + return info.Mode()&os.ModeCharDevice != 0 +} diff --git a/cmds/dutctl/term_test.go b/cmds/dutctl/term_test.go new file mode 100644 index 00000000..60d6b400 --- /dev/null +++ b/cmds/dutctl/term_test.go @@ -0,0 +1,30 @@ +// Copyright 2025 Blindspot Software +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +package main + +import ( + "bytes" + "os" + "testing" +) + +func TestIsTerminal(t *testing.T) { + // A non-*os.File writer is never a terminal. + if isTerminal(&bytes.Buffer{}) { + t.Error("bytes.Buffer should not be reported as a terminal") + } + + // A regular file is not a character device, so it is not a terminal — this + // is the case that matters: redirected output must not get color. + file, err := os.CreateTemp(t.TempDir(), "tty") + if err != nil { + t.Fatal(err) + } + defer file.Close() + + if isTerminal(file) { + t.Error("a regular file should not be reported as a terminal") + } +} diff --git a/internal/output/json.go b/internal/output/json.go index bfe0a804..0bfd2ae4 100644 --- a/internal/output/json.go +++ b/internal/output/json.go @@ -8,7 +8,7 @@ import ( "encoding/json" "fmt" "io" - "log" + "log/slog" "time" ) @@ -70,7 +70,7 @@ func (f *JSONFormatter) WriteContent(content Content) { bytes, err := json.MarshalIndent(output, "", " ") if err != nil { - log.Printf("Error marshaling JSON: %v", err) + slog.Warn("failed to render output", "format", "json", "err", err) return } diff --git a/internal/output/oneline.go b/internal/output/oneline.go index c97dd4a1..b613af98 100644 --- a/internal/output/oneline.go +++ b/internal/output/oneline.go @@ -121,6 +121,13 @@ func formatDataValue(data interface{}, separator string) string { return formatQuotedString(strings.Join(entries, "|"), separator) case DeviceEntry: return formatQuotedString(deviceEntryString(dataValue), separator) + case FileTransfer: + // Path goes last so it stays unambiguous even when it contains the + // separator or a colon (e.g. Windows paths like C:\...); the whole + // field is quoted by formatQuotedString. + token := fmt.Sprintf("%s %d %s", dataValue.Direction, dataValue.Bytes, dataValue.Path) + + return formatQuotedString(token, separator) default: // Convert anything else to string return formatQuotedString(fmt.Sprintf("%v", dataValue), separator) diff --git a/internal/output/output.go b/internal/output/output.go index 12dd70a8..8e00af2c 100644 --- a/internal/output/output.go +++ b/internal/output/output.go @@ -33,6 +33,9 @@ const ( // TypeLockResult represents the result of a lock or unlock operation. TypeLockResult ContentType = "lock-result" + + // TypeFileTransfer represents a file transferred between client and agent. + TypeFileTransfer ContentType = "file-transfer" ) // DeviceEntry describes a device and its lock state for TypeDeviceList output. @@ -43,6 +46,14 @@ type DeviceEntry struct { ExpiresAt int64 // Unix seconds, 0 means no expiry. } +// FileTransfer describes a file sent to or received from the agent for +// TypeFileTransfer output. Direction is "sent" or "received". +type FileTransfer struct { + Direction string `json:"direction" yaml:"direction"` + Path string `json:"path" yaml:"path"` + Bytes int `json:"bytes" yaml:"bytes"` +} + // Content is a structured data unit to be formatted and displayed. type Content struct { // Type identifies the category of this content. diff --git a/internal/output/text.go b/internal/output/text.go index a49bb94a..5618643a 100644 --- a/internal/output/text.go +++ b/internal/output/text.go @@ -12,6 +12,8 @@ import ( "slices" "strings" "time" + + "github.com/BlindspotSoftware/dutctl/internal/style" ) // TextFormatter implements Formatter with plain text formatting capabilities. @@ -29,7 +31,7 @@ type TextFormatter struct { errBuffer bytes.Buffer metadataCache map[string]string // Cache to remember last printed metadata isLastWriteToStderr bool // Tracks if the last metadata write was to stderr (true) or stdout (false) - invertedMetadata bool // Controls whether metadata is displayed with inverted colors + useColor bool // Whether colored output is enabled } // newTextFormatter creates a new TextFormatter instance configured according to the provided Config. @@ -45,12 +47,12 @@ func newTextFormatter(config Config) *TextFormatter { } return &TextFormatter{ - stdout: config.Stdout, - stderr: config.Stderr, - verbose: config.Verbose, - buffering: false, - metadataCache: make(map[string]string), - invertedMetadata: !config.NoColor, // Enable inverted metadata by default unless NoColor is set + stdout: config.Stdout, + stderr: config.Stderr, + verbose: config.Verbose, + buffering: false, + metadataCache: make(map[string]string), + useColor: !config.NoColor, } } @@ -94,6 +96,8 @@ func (f *TextFormatter) WriteContent(content Content) { f.writeModuleOutputTo(content, writer) case TypeLockResult: f.writeLockResultTo(content, writer) + case TypeFileTransfer: + f.writeFileTransferTo(content, writer) default: // For general text or unrecognized types f.writeGeneralTo(content, writer) @@ -179,6 +183,24 @@ func humanDuration(dur time.Duration) string { } } +// humanBytes renders a byte count as a compact "1.2 MiB"-style string using +// binary (1024) units. Counts below 1 KiB are shown as plain bytes. +func humanBytes(byteCount int) string { + const unit = 1024 + + if byteCount < unit { + return fmt.Sprintf("%d B", byteCount) + } + + div, exp := int64(unit), 0 + for v := int64(byteCount) / unit; v >= unit; v /= unit { + div *= unit + exp++ + } + + return fmt.Sprintf("%.1f %ciB", float64(byteCount)/float64(div), "KMGTPE"[exp]) +} + // lockAnnotation renders the bracketed lock note for a locked device, e.g. // ` [locked by "alice@host" for 25m]`. ExpiresAt of 0 omits the duration. func lockAnnotation(entry DeviceEntry) string { @@ -205,7 +227,10 @@ func (f *TextFormatter) writeDeviceListTo(content Content, writer io.Writer) { for _, device := range devices { if device.Locked { - fmt.Fprintf(writer, "- %s%s\n", device.Name, lockAnnotation(device)) + // The device name is the payload; the lock note is secondary context, + // so it is muted (gray). + annotation := style.Colorize(f.useColor, style.Gray, lockAnnotation(device)) + fmt.Fprintf(writer, "- %s%s\n", device.Name, annotation) } else { fmt.Fprintf(writer, "- %s\n", device.Name) } @@ -223,15 +248,41 @@ func (f *TextFormatter) writeLockResultTo(content Content, writer io.Writer) { f.writeMetadata(content, writer) + var msg string + switch { case !entry.Locked: - fmt.Fprintf(writer, "Device %q unlocked\n", entry.Name) + msg = fmt.Sprintf("Device %q unlocked", entry.Name) case entry.ExpiresAt == 0: - fmt.Fprintf(writer, "Device %q locked by %q\n", entry.Name, entry.Owner) + msg = fmt.Sprintf("Device %q locked by %q", entry.Name, entry.Owner) default: remaining := humanDuration(time.Until(time.Unix(entry.ExpiresAt, 0))) - fmt.Fprintf(writer, "Device %q locked by %q for %s\n", entry.Name, entry.Owner, remaining) + msg = fmt.Sprintf("Device %q locked by %q for %s", entry.Name, entry.Owner, remaining) } + + line := style.MarkerSuccess + " " + msg + fmt.Fprintln(writer, style.Colorize(f.useColor, style.Green, line)) +} + +// writeFileTransferTo formats and writes a file-transfer progress line, e.g. +// `↑ sent "firmware.bin" (1.2 MiB)` / `↓ received "result.log" (4.0 KiB)`. +func (f *TextFormatter) writeFileTransferTo(content Content, writer io.Writer) { + transfer, ok := content.Data.(FileTransfer) + if !ok { + f.writeGeneralTo(content, writer) + + return + } + + f.writeMetadata(content, writer) + + marker := style.MarkerSent + if transfer.Direction == "received" { + marker = style.MarkerReceived + } + + line := fmt.Sprintf("%s %s %q (%s)", marker, transfer.Direction, transfer.Path, humanBytes(transfer.Bytes)) + fmt.Fprintln(writer, style.Colorize(f.useColor, style.Cyan, line)) } // writeCommandListTo formats and writes a list of commands with bullet points. @@ -291,7 +342,15 @@ func (f *TextFormatter) writeGeneralTo(content Content, writer io.Writer) { switch data := content.Data.(type) { case string: - fmt.Fprint(writer, data) + // A string flagged as an error gets the error marker/color; IsError here + // means "client error" because device stderr is TypeModuleOutput and is + // rendered elsewhere. + if content.IsError { + line := style.MarkerError + " " + strings.TrimRight(data, "\n") + fmt.Fprintln(writer, style.Colorize(f.useColor, style.Red, line)) + } else { + fmt.Fprint(writer, data) + } case []byte: fmt.Fprint(writer, string(data)) case []string: @@ -315,21 +374,13 @@ func (f *TextFormatter) writeMetadata(content Content, writer io.Writer) { return } - // ANSI escape codes for inverted text and reset - only used if invertedMetadata is true - const ( - invertCode = "\033[7m" // Invert colors - resetCode = "\033[0m" // Reset formatting - ) - - // Process metadata that should be printed + // Process metadata that should be printed. Context lines are muted (gray) + // so they sit visually below the payload. knownMetadata, otherMetadata := splitMetadata(content.Metadata) if sentence := metadataText(knownMetadata); sentence != "" { - if f.invertedMetadata { - fmt.Fprintf(writer, "%s# %s%s\n", invertCode, sentence, resetCode) - } else { - fmt.Fprintf(writer, "# %s\n", sentence) - } + line := style.MarkerContext + " " + sentence + fmt.Fprintln(writer, style.Colorize(f.useColor, style.Gray, line)) } // Print all remaining metadata on a single line, sorted by keys @@ -342,11 +393,8 @@ func (f *TextFormatter) writeMetadata(content Content, writer io.Writer) { slices.Sort(keys) for _, key := range keys { - if f.invertedMetadata { - fmt.Fprintf(writer, "%s# %s: %s%s\n", invertCode, key, otherMetadata[key], resetCode) - } else { - fmt.Fprintf(writer, "# %s: %s\n", key, otherMetadata[key]) - } + line := fmt.Sprintf("%s %s: %s", style.MarkerContext, key, otherMetadata[key]) + fmt.Fprintln(writer, style.Colorize(f.useColor, style.Gray, line)) } } diff --git a/internal/output/text_test.go b/internal/output/text_test.go index d37ce887..5f7eaa38 100644 --- a/internal/output/text_test.go +++ b/internal/output/text_test.go @@ -312,7 +312,9 @@ func TestMetadataCaching(t *testing.T) { func TestWriteDeviceList(t *testing.T) { stdout := &bytes.Buffer{} - formatter := newTextFormatter(Config{Stdout: stdout, Stderr: &bytes.Buffer{}}) + // NoColor for deterministic output: the muted lock annotation is asserted + // without ANSI codes interleaving with the bracket text. + formatter := newTextFormatter(Config{Stdout: stdout, Stderr: &bytes.Buffer{}, NoColor: true}) formatter.WriteContent(Content{ Type: TypeDeviceList, @@ -345,24 +347,26 @@ func TestWriteLockResult(t *testing.T) { { name: "timed lock", data: DeviceEntry{Name: "my-board", Locked: true, Owner: "alice@host", ExpiresAt: time.Now().Add(30 * time.Minute).Unix()}, - want: `Device "my-board" locked by "alice@host" for 30m`, + want: `✓ Device "my-board" locked by "alice@host" for 30m`, }, { name: "auto lock without expiry", data: DeviceEntry{Name: "my-board", Locked: true, Owner: "alice@host"}, - want: `Device "my-board" locked by "alice@host"` + "\n", + want: `✓ Device "my-board" locked by "alice@host"` + "\n", }, { name: "unlock", data: DeviceEntry{Name: "my-board"}, - want: `Device "my-board" unlocked`, + want: `✓ Device "my-board" unlocked`, }, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { stdout := &bytes.Buffer{} - formatter := newTextFormatter(Config{Stdout: stdout, Stderr: &bytes.Buffer{}}) + // NoColor for deterministic output: the success marker and text are + // asserted without ANSI codes interleaving. + formatter := newTextFormatter(Config{Stdout: stdout, Stderr: &bytes.Buffer{}, NoColor: true}) formatter.WriteContent(Content{Type: TypeLockResult, Data: tt.data}) @@ -372,3 +376,92 @@ func TestWriteLockResult(t *testing.T) { }) } } + +func TestWriteError(t *testing.T) { + var stdout, stderr bytes.Buffer + + f := newTextFormatter(Config{Stdout: &stdout, Stderr: &stderr, NoColor: true}) + f.WriteContent(Content{Type: TypeGeneral, Data: "unavailable: connection refused", IsError: true}) + + // Errors carry the error marker, go to stderr, and never touch stdout. + if stdout.Len() != 0 { + t.Errorf("error leaked to stdout: %q", stdout.String()) + } + + if got, want := stderr.String(), "✗ unavailable: connection refused\n"; got != want { + t.Errorf("error output = %q, want %q", got, want) + } +} + +func TestWriteFileTransfer(t *testing.T) { + tests := []struct { + name string + data FileTransfer + want string + }{ + { + name: "sent", + data: FileTransfer{Direction: "sent", Path: "firmware.bin", Bytes: 1258291}, + want: "↑ sent \"firmware.bin\" (1.2 MiB)\n", + }, + { + name: "received", + data: FileTransfer{Direction: "received", Path: "result.log", Bytes: 4096}, + want: "↓ received \"result.log\" (4.0 KiB)\n", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var stdout, stderr bytes.Buffer + + f := newTextFormatter(Config{Stdout: &stdout, Stderr: &stderr, NoColor: true}) + f.WriteContent(Content{Type: TypeFileTransfer, Data: tt.data}) + + if got := stdout.String(); got != tt.want { + t.Errorf("file-transfer output = %q, want %q", got, tt.want) + } + + if stderr.Len() != 0 { + t.Errorf("unexpected stderr output: %q", stderr.String()) + } + }) + } +} + +func TestWriteFileTransferColored(t *testing.T) { + var stdout, stderr bytes.Buffer + + f := newTextFormatter(Config{Stdout: &stdout, Stderr: &stderr, NoColor: false}) + f.WriteContent(Content{ + Type: TypeFileTransfer, + Data: FileTransfer{Direction: "sent", Path: "fw.bin", Bytes: 1024}, + }) + + out := stdout.String() + if !strings.Contains(out, "\033[36m") || !strings.Contains(out, "\033[0m") { + t.Errorf("expected ANSI colour codes when colour enabled, got %q", out) + } +} + +func TestHumanBytes(t *testing.T) { + tests := []struct { + in int + want string + }{ + {0, "0 B"}, + {512, "512 B"}, + {1023, "1023 B"}, + {1024, "1.0 KiB"}, + {4096, "4.0 KiB"}, + {1258291, "1.2 MiB"}, + {1024 * 1024, "1.0 MiB"}, + {1024 * 1024 * 1024, "1.0 GiB"}, + } + + for _, tt := range tests { + if got := humanBytes(tt.in); got != tt.want { + t.Errorf("humanBytes(%d) = %q, want %q", tt.in, got, tt.want) + } + } +} diff --git a/internal/output/yaml.go b/internal/output/yaml.go index f6fae4b2..2dcebaad 100644 --- a/internal/output/yaml.go +++ b/internal/output/yaml.go @@ -7,7 +7,7 @@ package output import ( "fmt" "io" - "log" + "log/slog" "time" "gopkg.in/yaml.v3" @@ -68,7 +68,7 @@ func (f *YAMLFormatter) WriteContent(content Content) { bytes, err := yaml.Marshal(output) if err != nil { - log.Printf("Error marshaling YAML: %v", err) + slog.Warn("failed to render output", "format", "yaml", "err", err) return } @@ -108,7 +108,7 @@ func output(outputs []YAMLOutput, writer io.Writer) { for _, output := range outputs { bytes, err := yaml.Marshal(output) if err != nil { - log.Printf("Error marshaling YAML during flush: %v", err) + slog.Warn("failed to render output", "format", "yaml", "err", err) continue } diff --git a/internal/style/style.go b/internal/style/style.go new file mode 100644 index 00000000..f1e6a6aa --- /dev/null +++ b/internal/style/style.go @@ -0,0 +1,39 @@ +// Copyright 2025 Blindspot Software +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// Package style holds the shared visual vocabulary for the client's +// human-readable output. +package style + +// ANSI color codes. +const ( + Reset = "\033[0m" + Gray = "\033[90m" // muted: context / metadata + Cyan = "\033[36m" // info: file transfer + Yellow = "\033[33m" // warning + Red = "\033[31m" // error + Green = "\033[32m" // success +) + +// Markers prefix a line of certain client output so it is visually +// distinct from payload, which carries no marker. +const ( + MarkerContext = "#" // metadata / context + MarkerSent = "↑" // file sent to the agent + MarkerReceived = "↓" // file received from the agent + MarkerSuccess = "✓" // a successful action + MarkerWarning = "⚠" // a warning + MarkerError = "✗" // an error +) + +// Colorize wraps s in code (followed by Reset) when enabled is true and code is +// non-empty; otherwise it returns s unchanged. This is the single place that +// decides whether color is emitted. +func Colorize(enabled bool, code, s string) string { + if !enabled || code == "" { + return s + } + + return code + s + Reset +}