Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 2 additions & 1 deletion docs/content/docs/architecture/library-decisions.md
Original file line number Diff line number Diff line change
Expand Up @@ -154,7 +154,8 @@ Backwards compatibility layer is **not** used.

- Zero additional dependency.
- Structured key-value fields give context to debug messages.
- Silent by default; activated by `--debug` on the root command.
- Silent by default — `output.LevelSilent` sits above every level slog defines, so the silence
holds regardless of what level a new log point uses; activated by `--debug` on the root command.

---

Expand Down
3 changes: 2 additions & 1 deletion docs/content/docs/architecture/output.md
Original file line number Diff line number Diff line change
Expand Up @@ -90,7 +90,8 @@ nothing, because the next line rejects it.
explanation with `Info`.

`slog` is a third channel and not part of this contract: a debug-only diagnostic stream on stderr.
See [Logging](overview#logging).
`SetupLogger` in `log.go` is the only place its handler is built, and its default level is
`LevelSilent`, so nothing reaches a user who did not ask for it. See [Logging](overview#logging).

---

Expand Down
43 changes: 29 additions & 14 deletions docs/content/docs/architecture/overview.md
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ specs-cli/
│ └── errors.go # sentinel errors
├── cmd/ # one file per Cobra command
│ ├── root.go
│ ├── app.go # App struct, --debug/--safe-mode flags
│ ├── app.go # App struct, shared dependencies
│ ├── use.go # specs use <source> <target-dir>
│ ├── template.go # specs template subcommand group
│ ├── template_download.go
Expand Down Expand Up @@ -63,7 +63,7 @@ specs-cli/
├── exit/ # exit codes
├── git/ # go-git wrapper, SSH auth, remote check
├── osutil/ # file operations (CopyDir, etc.)
├── output/ # lipgloss-based logger + table renderer
├── output/ # Writer implementations, table renderer, slog setup
├── validate/ # Name() validator and argument validators
└── values/ # --values file (JSON/YAML) + --arg flag parsing
```
Expand Down Expand Up @@ -286,20 +286,36 @@ See [Output](output) for the full contract, the colour and width decisions and t

`specs` uses `log/slog` for structured diagnostic output. All packages emit logs via the
package-level `slog.Debug/Info/Warn/Error` functions, which route through the global default
logger. `NewApp()` calls `slog.SetDefault` to install a text handler at `Info` level;
`PersistentPreRunE` re-sets it when `--debug --output=json` swaps the handler to JSON.
logger.

`slog` is a **debug-only diagnostic channel** on **stderr** — it is silent on a normal run (every
log point is `Debug`, suppressed at the default `Info` level) and is distinct from the two
`output.Writer` formats (`pretty`/`json`) that produce user-facing output on stdout. Do not use
`slog` for user-facing reporting; use `output.Writer`.
`slog` is a **debug-only diagnostic channel** on **stderr** — silent on a normal run, and distinct
from the two `output.Writer` formats (`pretty`/`json`) that produce user-facing output on stdout.
Do not use `slog` for user-facing reporting; use `output.Writer`.

That silence is **enforced, not conventional**. `output.LevelSilent` is `slog.LevelError + 1`, above
every level slog defines, and it is the level a run without `--debug` gets — so a `slog.Info` or
`slog.Warn` added anywhere in the tree still writes nothing. It does not depend on every log point
happening to be `Debug`.

### One constructor, called twice

`output.SetupLogger(w io.Writer, format Format, debug bool) *slog.LevelVar` is the only place a
handler is built. It installs the process-wide default and returns the `LevelVar` gating it:

| Caller | Stream | Why |
|---------------------|---------------------|------------------------------------------------------------------------------------------------------------------------------|
| `NewApp()` | `os.Stderr` | Cobra parses persistent flags only after the tree is built, so a failure before that still needs a logger. Silent, `pretty`. |
| `PersistentPreRunE` | `cmd.ErrOrStderr()` | The flags are now resolved. Writing to the command's own stderr is what lets a test assert on `--debug` output. |

### Flags

| Flag | Effect |
|-----------------------------|-------------------------------------------------------------------------------------------------------------------------------|
| `--debug` | Raises the slog level from `Info` to `Debug`; all debug logs become visible |
| `--output=json` + `--debug` | Swaps the slog handler to `slog.NewJSONHandler` writing to stderr; debug logs are emitted as NDJSON distinct from stdout data |
| Flag | Effect |
|-----------------------------|--------------------------------------------------------------------------------|
| *(neither)* | Level `LevelSilent` — nothing is emitted at any level |
| `--debug` | Level `Debug`, text records on stderr |
| `--debug` + `--output=json` | Level `Debug`, JSON records on stderr, so that stream is JSON all the way down |

`--output` alone does not change logging: without `--debug` there is nothing to format.

### Log points

Expand Down Expand Up @@ -345,8 +361,7 @@ specs --debug --output=json template ls 2>debug.ndjson
```

`--output=json` controls the **data** format on stdout; `--debug` + `--output=json` controls
the **log** format on stderr. The two streams are independent. `slog.SetDefault` is called
by `NewApp()` and re-set in `PersistentPreRunE` when `--debug --output=json` swaps the handler.
the **log** format on stderr. The two streams are independent.

---

Expand Down
66 changes: 11 additions & 55 deletions internal/cmd/app.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,6 @@ package cmd

import (
"context"
"log/slog"
"os"
"time"

Expand All @@ -11,45 +10,9 @@ import (
"github.com/specsnl/specs-cli/internal/util/output"
)

// HandlerFactory creates a slog.Handler wired to the given LevelVar.
// The LevelVar is passed so that WithDebug can adjust the level at runtime
// regardless of which handler is in use.
type HandlerFactory func(level *slog.LevelVar) slog.Handler

// Option is a functional option for configuring an App.
type Option func(*App)

// WithDebug returns an Option that sets the log level to debug when enabled,
// or back to info when false.
func WithDebug(enabled bool) Option {
return func(a *App) {
if enabled {
a.level.Set(slog.LevelDebug)
} else {
a.level.Set(slog.LevelInfo)
}
}
}

// WithHandler returns an Option that replaces the global default logger with one
// built by the provided factory. The factory receives the App's LevelVar so the
// handler can honour runtime level changes from WithDebug.
//
// Example — switch to JSON output:
//
// app := NewApp(WithHandler(func(level *slog.LevelVar) slog.Handler {
// return slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: level})
// }))
func WithHandler(factory HandlerFactory) Option {
return func(a *App) {
slog.SetDefault(slog.New(factory(a.level)))
}
}

// App holds application-wide dependencies shared across all commands.
type App struct {
Output output.Writer
level *slog.LevelVar
SafeMode bool
HookEnvPrefix string // prefix for context keys injected as env vars into hooks

Expand All @@ -62,29 +25,22 @@ type App struct {
refreshTimeout time.Duration
}

// NewApp creates an App. The default logger writes text to stderr at info level and
// is registered as the global slog default. Use WithHandler to substitute a different
// handler; use WithDebug to raise the level.
// Options are applied in order after the default logger is initialised.
func NewApp(opts ...Option) *App {
level := new(slog.LevelVar)
level.Set(slog.LevelInfo)

slog.SetDefault(slog.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{Level: level})))

app := &App{
// NewApp creates an App.
//
// The logger it installs is silent: nothing is emitted until PersistentPreRunE
// calls output.SetupLogger again with the resolved --debug and --output flags.
// This first call exists only so that a failure before flag parsing has a
// default logger to reach, and it writes to os.Stderr because no command — and
// therefore no cmd.ErrOrStderr() — exists yet.
func NewApp() *App {
output.SetupLogger(os.Stderr, output.FormatPretty, false)

return &App{
Output: output.NewDefaultPrettyWriter(),
level: level,
checkRemoteFn: pkggit.CheckRemoteContext,
checkTimeout: 10 * time.Second,
refreshTimeout: 30 * time.Second,
}

for _, opt := range opts {
opt(app)
}

return app
}

// templateConfig translates App-level flags into a template.Config.
Expand Down
16 changes: 4 additions & 12 deletions internal/cmd/root.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@ package cmd
import (
"context"
"fmt"
"log/slog"

"github.com/spf13/cobra"

Expand Down Expand Up @@ -60,17 +59,10 @@ Use "specs <command> --help" for more information about a command.`,
outputFlag, output.FormatPretty, output.FormatJSON)
}

// Configure the slog logger level; swap to JSON handler when both
// --debug and --output=json are set.
if debug {
app.level.Set(slog.LevelDebug)

if format == output.FormatJSON {
slog.SetDefault(slog.New(slog.NewJSONHandler(cmd.ErrOrStderr(), &slog.HandlerOptions{Level: app.level})))
}
} else {
app.level.Set(slog.LevelInfo)
}
// Re-install the logger now the flags are known: on the command's own
// stderr, so a test can read what --debug wrote, and in the format
// --output selected. Without --debug it is silent.
output.SetupLogger(cmd.ErrOrStderr(), format, debug)

return nil
},
Expand Down
79 changes: 79 additions & 0 deletions internal/cmd/root_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package cmd
import (
"bytes"
"fmt"
"log/slog"
"strings"
"testing"

Expand Down Expand Up @@ -45,6 +46,25 @@ func executeCmdStreams(args ...string) (stdout, stderr string, err error) {
return out.String(), errOut.String(), err
}

// executeCmdStreamsWith runs the command and then calls emit, which stands in
// for a log point somewhere in the tree. It runs after Execute rather than
// during it because the logger PersistentPreRunE installed is process-wide and
// still in place — so whatever emit writes lands wherever a real log point
// would have, without needing a command that happens to log.
func executeCmdStreamsWith(emit func(), args ...string) (stdout, stderr string, err error) {
app := NewApp()
cmd := newRootCmd(app)
out, errOut := new(bytes.Buffer), new(bytes.Buffer)
cmd.SetOut(out)
cmd.SetErr(errOut)
cmd.SetArgs(args)
err = cmd.Execute()

emit()

return out.String(), errOut.String(), err
}

func TestHelp_ExitsZero(t *testing.T) {
out, err := executeCmd("--help")
if err != nil {
Expand Down Expand Up @@ -108,6 +128,65 @@ func TestOutputFlag_InvalidIsRejected(t *testing.T) {
}
}

// The logger PersistentPreRunE installs writes to the command's own stderr, so
// a test can read what --debug produced instead of it escaping to os.Stderr.
func TestDebugFlag_Logging(t *testing.T) {
tests := []struct {
name string
args []string
assert func(t *testing.T, stderr string)
}{
{
name: "silent without --debug",
args: []string{"version"},
assert: func(t *testing.T, stderr string) {
t.Helper()

if strings.Contains(stderr, "level=") || strings.Contains(stderr, `"level":"DEBUG"`) {
t.Errorf("stderr = %q, want no log records without --debug", stderr)
}
},
},
{
name: "--debug emits text records",
args: []string{"--debug", "version"},
assert: func(t *testing.T, stderr string) {
t.Helper()

if !strings.Contains(stderr, "level=DEBUG") {
t.Errorf("stderr = %q, want a text record", stderr)
}
},
},
{
name: "--debug -o json emits JSON records",
args: []string{"--debug", "-o", "json", "version"},
assert: func(t *testing.T, stderr string) {
t.Helper()

if !strings.Contains(stderr, `"level":"DEBUG"`) {
t.Errorf("stderr = %q, want a JSON record", stderr)
}
},
},
}

for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
previous := slog.Default()

t.Cleanup(func() { slog.SetDefault(previous) })

_, stderr, err := executeCmdStreamsWith(func() { slog.Debug("a diagnostic") }, tt.args...)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}

tt.assert(t, stderr)
})
}
}

func TestHookEnvPrefix_Default(t *testing.T) {
app, _, err := executeCmdWithApp("version")
if err != nil {
Expand Down
3 changes: 0 additions & 3 deletions internal/cmd/template_validate.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@ package cmd
import (
"errors"
"fmt"
"log/slog"
"os"
"path/filepath"

Expand All @@ -21,8 +20,6 @@ func newTemplateValidateCmd(app *App) *cobra.Command {
Short: "Validate a template directory",
Args: cobra.ExactArgs(1),
RunE: func(cmd *cobra.Command, args []string) error {
app.level.Set(slog.LevelDebug)

templateRoot := args[0]

templateDir := filepath.Join(templateRoot, specs.TemplateDirFile)
Expand Down
50 changes: 50 additions & 0 deletions internal/util/output/log.go
Original file line number Diff line number Diff line change
@@ -1 +1,51 @@
package output

import (
"io"
"log/slog"
)

// LevelSilent is above every level slog defines, so a logger set to it emits
// nothing at all — not even slog.Error.
//
// It is the default because slog is a diagnostic channel for someone debugging
// specs, not a reporting channel for someone using it: everything a user should
// see goes through Writer. Making silence the level rather than a convention is
// what keeps that true when the first slog.Info is added to the tree.
const LevelSilent = slog.LevelError + 1

// SetupLogger installs the process-wide default slog logger on w and returns the
// LevelVar gating it. debug selects slog.LevelDebug; otherwise the level is
// LevelSilent and nothing is written. The handler matches format, so
// `--debug -o json` yields a stderr stream that is JSON all the way down.
//
// The level is returned rather than baked in because cobra parses persistent
// flags only after the command tree is built: NewApp calls this with a silent
// default so a failure before flag parsing still has somewhere to go, and
// PersistentPreRunE calls it again with the command's own stderr and the
// resolved flags.
func SetupLogger(w io.Writer, format Format, debug bool) *slog.LevelVar {
level := new(slog.LevelVar)
if debug {
level.Set(slog.LevelDebug)
} else {
level.Set(LevelSilent)
}

slog.SetDefault(slog.New(newHandler(w, format, level)))

return level
}

// newHandler builds the handler for a format: JSON records for FormatJSON, text
// for everything else. An unrecognised format still has to log somewhere, and
// text is what a human reading a terminal wants.
func newHandler(w io.Writer, format Format, level slog.Leveler) slog.Handler {
opts := &slog.HandlerOptions{Level: level}

if format == FormatJSON {
return slog.NewJSONHandler(w, opts)
}

return slog.NewTextHandler(w, opts)
}
Loading