diff --git a/CLAUDE.md b/CLAUDE.md index 3a60100..9d5d69a 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -48,7 +48,18 @@ Three files split cleanly along "engine vs. two interchangeable front-ends": something looks off after a resize. - **[main.go](main.go)** — CLI flag definitions (`urfave/cli/v3`) and the interactive/plain dispatch: `isInteractiveTerminal()` checks stdout *and* stderr are TTYs, `--no-tui` forces - plain mode even in a terminal. + plain mode even in a terminal. `resolveLogDir()` turns `--log-dir`/`LOADER_LOG_DIR` (or the + `.loader` default) into a fresh timestamped subfolder per run (UTC, colon-free so it's valid + on filesystems like NTFS — see `logDirTimeFormat`); `--no-log` leaves + `Config.LogDir` empty to disable logging entirely. +- **[logdir.go](logdir.go)** — `RunLogger`, the optional on-disk logger for a single run's log + artifacts: `environment.log` (the environment loader saw at startup), one `proc-N.log` per + launched process (combined stdout/stderr, matched by `LOADER_RUN_ATTEMPT`), `run.log` (one + timestamped start/stop line per launch, written by `LogStart`/`LogStop` from `launchOne` and + mirroring the TUI's recent-activity feed), and `summary.log` (config + final stats, written + once by `Engine.Run` after `FinalSnapshot()`, which also closes the run log). A nil + `*RunLogger` is a safe no-op, so `Engine` doesn't need a separate enabled/disabled branch. + `FormatConfig()` here is shared by `plain.go`'s startup header and `summary.log`. Both drivers talk to `Engine` through the same public surface (`Run`, `Snapshot`, `FinalSnapshot`, `LogLines`, `StopLaunching`, `KillRunning`, `Stopping`, `Finished`) — there is diff --git a/README.md b/README.md index 7aea045..c329180 100644 --- a/README.md +++ b/README.md @@ -42,6 +42,8 @@ loader [options] COMMAND [ARGS...] | `--duration` | `-d` | `0` | Stop launching after this duration (0 = unlimited) | | `--verbose` | | off | Show stdout/stderr from each process (non-TUI mode) | | `--no-tui` | | off | Force plain-text output instead of the fullscreen TUI | +| `--log-dir` | | `.loader` | Directory to write per-run log files into (gets its own timestamped subfolder); also settable via `LOADER_LOG_DIR` | +| `--no-log` | | off | Disable writing per-run log files | At least one of `--max-count` or `--duration` must be set, otherwise the tool runs until interrupted. @@ -73,10 +75,27 @@ loader -d 60s -r 0s -p 100 -- curl -s http://localhost:8080/health - **Ctrl-C twice** (or `q` twice) — kills all running processes and finishes immediately. - Subprocess stdout/stderr is discarded by default; use `--verbose` to see it. - Each launched process inherits the environment plus: - - `LOADER_ITERATION_ID` — the 0-based launch counter for this process + - `LOADER_RUN_ATTEMPT` — the 1-based launch counter for this process - `LOADER_RATE` — the configured `--rate` value - `LOADER_MAX_PARALLEL` — the configured `--max-parallel` value +## Log files + +Unless `--no-log` is set, each run writes its log files to a fresh +timestamped subfolder (e.g. `2026-09-24T15-04-21Z`, UTC) under `--log-dir` +(default `.loader`), so repeated runs never clobber each other: + +- `environment.log` — the environment loader saw at startup, one `KEY=value` per line +- `proc-N.log` — combined stdout/stderr for launched process `N` (matches `LOADER_RUN_ATTEMPT`) +- `run.log` — one timestamped line per start/stop event, mirroring the TUI's recent-activity feed: + + ``` + 2026-09-24T05:40:21.109+01:00 attempt=1 event=start + 2026-09-24T05:40:21.117+01:00 attempt=1 event=stop exit=1 duration=8ms + ``` + +- `summary.log` — the run's config followed by its final summary stats, written once the run finishes + ## Interactive mode In a terminal, `loader` runs as a fullscreen dashboard with: diff --git a/engine.go b/engine.go index 5b6be62..1a159cc 100644 --- a/engine.go +++ b/engine.go @@ -3,6 +3,7 @@ package main import ( "bytes" "context" + "errors" "fmt" "io" "math" @@ -91,6 +92,10 @@ type Config struct { // OutputMode controls how subprocess stdout/stderr is handled. See // OutputMode's docs. OutputMode OutputMode + + // LogDir is the resolved directory to write per-run log files into. + // Empty means logging is disabled. + LogDir string } // LogLine is a single line of output emitted by a process, or a system @@ -380,9 +385,10 @@ func (w *lineWriter) Flush() { // cfg.MaxCount/cfg.TestDuration, and tracking results. It is display-agnostic // — plain.go and tui.go both drive it the same way. type Engine struct { - cfg Config - stats stats - stage atomic.Int32 + cfg Config + stats stats + stage atomic.Int32 + logger *RunLogger logCh chan LogLine dropped atomic.Int64 @@ -405,9 +411,15 @@ type Engine struct { // NewEngine constructs an Engine ready to Run. Cancellation plumbing is set // up eagerly so StopLaunching/KillRunning are safe to call as soon as // NewEngine returns, even before Run's goroutine has started. -func NewEngine(cfg Config) *Engine { +func NewEngine(cfg Config) (*Engine, error) { + logger, err := newRunLogger(cfg.LogDir) + if err != nil { + return nil, err + } + e := &Engine{ cfg: cfg, + logger: logger, logCh: make(chan LogLine, logChannelCapacity), stoppingCh: make(chan struct{}), finishedCh: make(chan struct{}), @@ -423,7 +435,7 @@ func NewEngine(cfg Config) *Engine { e.runCtx, e.cancelRun = context.WithCancel(context.Background()) e.stage.Store(int32(StageRunning)) - return e + return e, nil } // Stage returns the engine's current lifecycle stage. @@ -635,6 +647,12 @@ launchLoop: e.setStageAtLeast(StageStopping) wg.Wait() e.setStageAtLeast(StageFinished) + if err := e.logger.WriteSummary(e.cfg, e.FinalSnapshot()); err != nil { + fmt.Fprintf(os.Stderr, "warning: failed to write log summary: %v\n", err) + } + if err := e.logger.Close(); err != nil { + fmt.Fprintf(os.Stderr, "warning: failed to close run log: %v\n", err) + } close(e.logCh) } @@ -642,6 +660,7 @@ func (e *Engine) launchOne(n int64) { start := time.Now() e.stats.startRunning(n, start) e.stats.recordStart(n, start) + e.logger.LogStart(n, start) defer e.stats.stopRunning(n) c := exec.CommandContext(e.runCtx, e.cfg.Args[0], e.cfg.Args[1:]...) @@ -658,7 +677,7 @@ func (e *Engine) launchOne(n int64) { } c.WaitDelay = 5 * time.Second c.Env = append(os.Environ(), - fmt.Sprintf("LOADER_ITERATION_ID=%d", n), + fmt.Sprintf("LOADER_RUN_ATTEMPT=%d", n), fmt.Sprintf("LOADER_RATE=%s", e.cfg.Rate), fmt.Sprintf("LOADER_MAX_PARALLEL=%d", e.cfg.MaxParallel), ) @@ -678,15 +697,41 @@ func (e *Engine) launchOne(n int64) { c.Stderr = io.Discard } + if e.logger != nil { + if f, ferr := os.Create(e.logger.processLogPath(n)); ferr == nil { + defer func() { _ = f.Close() }() + c.Stdout = io.MultiWriter(c.Stdout, f) + c.Stderr = io.MultiWriter(c.Stderr, f) + } else { + e.emitLog(LogLine{ProcID: n, Stream: "system", Text: fmt.Sprintf("failed to create process log file: %v", ferr)}) + } + } + err := c.Run() if stdoutW != nil { stdoutW.Flush() stderrW.Flush() } - elapsed := time.Since(start) + stop := time.Now() + elapsed := stop.Sub(start) e.stats.recordCompletion(n, elapsed, err) + e.logger.LogStop(n, stop, exitCode(err), elapsed) if err != nil && e.runCtx.Err() == nil { e.emitLog(LogLine{ProcID: n, Stream: "system", Text: fmt.Sprintf("error after %v: %v", elapsed, err)}) } } + +// exitCode extracts a process's exit code from the error c.Run() returned: +// 0 for a nil error, the child's actual code for an *exec.ExitError, or -1 +// for any other failure (e.g. the command couldn't be started at all). +func exitCode(err error) int { + if err == nil { + return 0 + } + var exitErr *exec.ExitError + if errors.As(err, &exitErr) { + return exitErr.ExitCode() + } + return -1 +} diff --git a/engine_test.go b/engine_test.go index 9fdffbd..a762da5 100644 --- a/engine_test.go +++ b/engine_test.go @@ -202,7 +202,10 @@ func TestEngineRunSuccess(t *testing.T) { MaxParallel: 5, MaxCount: 5, } - eng := NewEngine(cfg) + eng, err := NewEngine(cfg) + if err != nil { + t.Fatalf("NewEngine: %v", err) + } eng.Run() @@ -239,7 +242,10 @@ func TestEngineRunFailure(t *testing.T) { MaxParallel: 3, MaxCount: 3, } - eng := NewEngine(cfg) + eng, err := NewEngine(cfg) + if err != nil { + t.Fatalf("NewEngine: %v", err) + } eng.Run() @@ -269,7 +275,10 @@ func TestEngineSnapshotRunningProcs(t *testing.T) { MaxParallel: 3, MaxCount: 3, } - eng := NewEngine(cfg) + eng, err := NewEngine(cfg) + if err != nil { + t.Fatalf("NewEngine: %v", err) + } done := make(chan struct{}) go func() { diff --git a/logdir.go b/logdir.go new file mode 100644 index 0000000..e48f331 --- /dev/null +++ b/logdir.go @@ -0,0 +1,133 @@ +package main + +import ( + "fmt" + "os" + "path/filepath" + "sort" + "strings" + "sync" + "time" +) + +// runLogTimeFormat is the timestamp format used for each run.log line: +// millisecond-precision RFC3339, so lines sort lexically and stay readable. +const runLogTimeFormat = "2006-01-02T15:04:05.000Z07:00" + +// RunLogger writes the on-disk log artifacts for a single run: one combined +// stdout/stderr file per launched process, the environment loader saw, a +// start/stop event log mirroring the TUI's activity feed, and a final file +// combining the run's config with its summary stats. A nil *RunLogger means +// logging is disabled; every method is a safe no-op in that case so callers +// don't need a separate enabled/disabled branch. +type RunLogger struct { + dir string + + runLogMu sync.Mutex + runLog *os.File +} + +// newRunLogger creates dir and writes environment.log into it. An empty dir +// means logging is disabled, and returns (nil, nil). +func newRunLogger(dir string) (*RunLogger, error) { + if dir == "" { + return nil, nil + } + if err := os.MkdirAll(dir, 0o755); err != nil { + return nil, fmt.Errorf("create log directory: %w", err) + } + f, err := os.OpenFile(filepath.Join(dir, "run.log"), os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o644) + if err != nil { + return nil, fmt.Errorf("create run log: %w", err) + } + l := &RunLogger{dir: dir, runLog: f} + if err := l.writeEnvironment(); err != nil { + return nil, err + } + return l, nil +} + +// Dir returns the resolved log directory, or "" if l is nil. +func (l *RunLogger) Dir() string { + if l == nil { + return "" + } + return l.dir +} + +func (l *RunLogger) writeEnvironment() error { + env := os.Environ() + sort.Strings(env) + return os.WriteFile(filepath.Join(l.dir, "environment.log"), []byte(strings.Join(env, "\n")+"\n"), 0o644) +} + +// processLogPath returns the path to the combined stdout/stderr file for +// launched process n. +func (l *RunLogger) processLogPath(n int64) string { + return filepath.Join(l.dir, fmt.Sprintf("proc-%d.log", n)) +} + +// LogStart appends a start event for run attempt n to run.log. It's a no-op +// if l is nil. +func (l *RunLogger) LogStart(n int64, start time.Time) { + if l == nil { + return + } + l.writeRunLine(fmt.Sprintf("%s attempt=%d event=start\n", start.Format(runLogTimeFormat), n)) +} + +// LogStop appends a stop event for run attempt n to run.log, recording its +// exit code and duration. It's a no-op if l is nil. +func (l *RunLogger) LogStop(n int64, stop time.Time, exitCode int, d time.Duration) { + if l == nil { + return + } + l.writeRunLine(fmt.Sprintf("%s attempt=%d event=stop exit=%d duration=%s\n", + stop.Format(runLogTimeFormat), n, exitCode, d.Round(time.Millisecond))) +} + +func (l *RunLogger) writeRunLine(line string) { + l.runLogMu.Lock() + defer l.runLogMu.Unlock() + if _, err := l.runLog.WriteString(line); err != nil { + fmt.Fprintf(os.Stderr, "warning: failed to write run log: %v\n", err) + } +} + +// Close closes the run log file. It's a no-op if l is nil. +func (l *RunLogger) Close() error { + if l == nil { + return nil + } + return l.runLog.Close() +} + +// WriteSummary writes this run's config and final stats to summary.log. It's +// a no-op if l is nil. +func (l *RunLogger) WriteSummary(cfg Config, snap Snapshot) error { + if l == nil { + return nil + } + var b strings.Builder + b.WriteString(FormatConfig(cfg)) + b.WriteString("\n") + b.WriteString(FormatSummary(snap)) + return os.WriteFile(filepath.Join(l.dir, "summary.log"), []byte(b.String()), 0o644) +} + +// FormatConfig renders the config options a run was launched with, in the +// same form shown by plain mode's startup header and written to a run's +// summary.log. +func FormatConfig(cfg Config) string { + var b strings.Builder + fmt.Fprintf(&b, "command: %s\n", strings.Join(cfg.Args, " ")) + fmt.Fprintf(&b, "rate: %v\n", cfg.Rate) + fmt.Fprintf(&b, "max-parallel: %d\n", cfg.MaxParallel) + if cfg.MaxCount > 0 { + fmt.Fprintf(&b, "max-count: %d\n", cfg.MaxCount) + } + if cfg.TestDuration > 0 { + fmt.Fprintf(&b, "duration: %v\n", cfg.TestDuration) + } + return b.String() +} diff --git a/main.go b/main.go index 8132bfd..866913c 100644 --- a/main.go +++ b/main.go @@ -4,6 +4,7 @@ import ( "context" "fmt" "os" + "path/filepath" "time" "github.com/urfave/cli/v3" @@ -25,6 +26,23 @@ func outputMode(interactive, verbose bool) OutputMode { } } +// logDirTimeFormat names a run's timestamped subfolder: a UTC, colon-free +// variant of RFC3339 that stays valid on filesystems (like NTFS) where ':' +// isn't allowed in path names. +const logDirTimeFormat = "2006-01-02T15-04-05Z" + +// resolveLogDir returns the directory a run's log files should be written +// to: override (the --log-dir flag/LOADER_LOG_DIR value, or "" to use the +// default), with its own timestamped subfolder, so repeated runs never share +// a directory even when --log-dir is set. +func resolveLogDir(override string) string { + base := override + if base == "" { + base = ".loader" + } + return filepath.Join(base, time.Now().UTC().Format(logDirTimeFormat)) +} + func buildConfig(cmd *cli.Command, interactive bool) (Config, error) { args := cmd.Args().Slice() if len(args) == 0 { @@ -36,6 +54,11 @@ func buildConfig(cmd *cli.Command, interactive bool) (Config, error) { return Config{}, fmt.Errorf("--max-parallel must be greater than 0") } + var logDir string + if !cmd.Bool("no-log") { + logDir = resolveLogDir(cmd.String("log-dir")) + } + return Config{ Args: args, Rate: cmd.Duration("rate"), @@ -43,6 +66,7 @@ func buildConfig(cmd *cli.Command, interactive bool) (Config, error) { MaxCount: int(cmd.Int("max-count")), TestDuration: cmd.Duration("duration"), OutputMode: outputMode(interactive, cmd.Bool("verbose")), + LogDir: logDir, }, nil } @@ -107,6 +131,15 @@ func main() { Name: "no-tui", Usage: "force plain-text output instead of the fullscreen TUI", }, + &cli.StringFlag{ + Name: "log-dir", + Usage: "directory to write per-run log files into (gets its own timestamped subfolder); default: .loader", + Sources: cli.EnvVars("LOADER_LOG_DIR"), + }, + &cli.BoolFlag{ + Name: "no-log", + Usage: "disable writing per-run log files", + }, }, Action: run, } diff --git a/plain.go b/plain.go index c1ce28e..691b76d 100644 --- a/plain.go +++ b/plain.go @@ -4,7 +4,6 @@ import ( "fmt" "os" "os/signal" - "strings" "time" ) @@ -13,16 +12,14 @@ import ( // second, error lines printed as they occur, and a final summary. Used when // stdout/stderr isn't an interactive terminal. func runPlain(cfg Config) error { - eng := NewEngine(cfg) - - fmt.Fprintf(os.Stderr, "command: %s\n", strings.Join(cfg.Args, " ")) - fmt.Fprintf(os.Stderr, "rate: %v\n", cfg.Rate) - fmt.Fprintf(os.Stderr, "max-parallel: %d\n", cfg.MaxParallel) - if cfg.MaxCount > 0 { - fmt.Fprintf(os.Stderr, "max-count: %d\n", cfg.MaxCount) + eng, err := NewEngine(cfg) + if err != nil { + return err } - if cfg.TestDuration > 0 { - fmt.Fprintf(os.Stderr, "duration: %v\n", cfg.TestDuration) + + fmt.Fprint(os.Stderr, FormatConfig(cfg)) + if cfg.LogDir != "" { + fmt.Fprintf(os.Stderr, "log dir: %s\n", cfg.LogDir) } fmt.Fprintln(os.Stderr) diff --git a/tui.go b/tui.go index d643425..3b5ae35 100644 --- a/tui.go +++ b/tui.go @@ -45,7 +45,10 @@ var ( // runTUI drives an Engine with a fullscreen bubbletea dashboard. Used when // stdout/stderr is an interactive terminal. func runTUI(cfg Config) error { - eng := NewEngine(cfg) + eng, err := NewEngine(cfg) + if err != nil { + return err + } // bubbletea's default signal handler intercepts an external SIGINT // itself and quits immediately, before Update ever sees it — bypassing @@ -62,7 +65,7 @@ func runTUI(cfg Config) error { // renderFooter), so nothing extra happens here on stage transitions. eng.WatchInterrupts(sigCh, nil, nil) - _, err := p.Run() + _, err = p.Run() return err }