Skip to content
17 changes: 17 additions & 0 deletions dev-docs/ARCHITECTURE.md
Original file line number Diff line number Diff line change
Expand Up @@ -451,6 +451,23 @@ When a build-tool-primary detector (Maven, Gradle, Go, …) cannot produce a gra
- **Degradation vs hand-off.** Only a real primary failure (not-ready, applicability-check error, install failure, resolve error, empty graph, scope-filter error) is annotated and warned about. `Applicable() == false` with no error is designed chain hand-off (e.g. the npm lockfile detector deferring to the native detector when no lockfile exists) and stays quiet. In chained fallbacks the outermost real failure wins, since users care about the planned primary.
- **Default visibility.** At default verbosity the CLI logger is a no-op, so the authoritative channel is the `PipelineWarning` converted from the annotation after the parallel resolve phase — it renders as a ⚠ child in the scan/explain/diff progress UI, as a yellow notice in the text report, a warning blockquote in markdown, and a `resolution.fallback` object in scan JSON. A single Warn log (`pipeline: detector fell back`) fires per unique (subproject, primary, fallback) tuple for `-v` users.
- **Stage observability.** Pipeline stages (detection, consolidation, enrichment, reachability, policy evaluation) emit Info start/completion logs with counts and durations; consolidation stays logger-free and the pipeline logs around it. Detector-internal completion lines remain owned by the detectors themselves, and recoverable detector subprocess failures log at Warn, not Error, because the pipeline degrades and continues.
- **Secret-safe subprocess logs.** Subprocess owners log the executable,
sanitized argument list, and working directory at Debug. The shared logging
sanitizer removes credential-shaped flag values and URL user information
while preserving ordinary arguments for reproduction. Executable values are
resolved binary paths or names and are assumed not to contain arguments or
credentials. URL query values are not parsed as credentials, so callers must
not treat URL sanitization as a general query-string redactor. The engine
logs orchestration state but never logs raw `install_args`. At DEBUG
verbosity (`-vv`), subprocess stderr is streamed to Bomly's stderr so users
can diagnose package-manager, analyzer, matcher, Git, Java, and managed
plugin failures. It is hidden at lower verbosity and is not stored in
structured results. Because Bomly cannot reliably sanitize arbitrary tool
output, DEBUG logs may contain credentials or other sensitive values printed
by those tools and must be handled as sensitive data. The serialized
`DetectionRequest.AllowStdErrLogging` field lets protocol-v1 detectors see
that the user enabled this output; process-local `Stderr` and `Verbose`
fields carry the destination and compatibility signal for built-ins.

### Decision: detector logs are request-scoped by subproject

Expand Down
7 changes: 6 additions & 1 deletion docs/TROUBLESHOOTING.md
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,12 @@ The animation is also skipped automatically when `CI` or `BOMLY_QUIET` is set, a

## Need more detail

Re-run with `-v` (INFO) or `-vv` (DEBUG). DEBUG logs include exact subprocess command lines, cache keys, and per-package decisions, which is usually enough to file a useful bug report.
Re-run with `-v` (INFO) or `-vv` (DEBUG). DEBUG logs include subprocess
executables, credential-sanitized arguments, working directories, cache keys,
and per-package decisions. They also include raw stderr from invoked package
managers, analyzers, matchers, Git, Java, and managed plugins. Bomly cannot
reliably remove secrets from arbitrary tool output, so treat DEBUG logs as
sensitive data. INFO logs do not include raw subprocess stderr.

```bash
bomly scan --enrich -vv 2> bomly.log
Expand Down
2 changes: 1 addition & 1 deletion internal/analyzers/govulncheck/analyzer.go
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,7 @@ func (a Analyzer) Analyze(ctx context.Context, req model.AnalyzeRequest) (model.
}
runner := a.Runner
if runner == nil {
runner = NewRunner(logger)
runner = newRunnerWithStderr(logger, req.Stderr)
}

overallStart := time.Now()
Expand Down
29 changes: 11 additions & 18 deletions internal/analyzers/govulncheck/runner_library.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,9 @@ import (
"context"
"errors"
"fmt"
"io"

"github.com/bomly-dev/bomly-cli/internal/logging"
"go.uber.org/zap"
govulnscan "golang.org/x/vuln/scan"
)
Expand All @@ -18,12 +20,17 @@ func NewRunner(logger *zap.Logger) Runner {
return libraryRunner{logger: ensureLogger(logger)}
}

func newRunnerWithStderr(logger *zap.Logger, stderr io.Writer) Runner {
return libraryRunner{logger: ensureLogger(logger), stderr: stderr}
}

// libraryRunner is the in-process implementation of Runner. The Runner
// interface is preserved (rather than calling api.Build directly from
// the analyzer) so unit tests can inject a fakeRunner for deterministic
// behavior without a real Go toolchain.
type libraryRunner struct {
logger *zap.Logger
stderr io.Writer
}

func (libraryRunner) Name() string { return "library" }
Expand All @@ -36,10 +43,10 @@ func (r libraryRunner) Run(ctx context.Context, moduleDir string) (RunnerResult,
zap.Strings("args", args))

var stdout bytes.Buffer
var stderr bytes.Buffer
stderr := logging.NewCommandStderr(r.stderr, r.stderr != nil)
cmd := govulnscan.Command(ctx, args...)
cmd.Stdout = &stdout
cmd.Stderr = &stderr
cmd.Stderr = stderr

if err := cmd.Start(); err != nil {
return RunnerResult{}, fmt.Errorf("govulncheck start: %w", err)
Expand All @@ -48,7 +55,7 @@ func (r libraryRunner) Run(ctx context.Context, moduleDir string) (RunnerResult,
r.logger.Debug("govulncheck: in-process runner produced output",
zap.String("module_root", moduleDir),
zap.Int("stdout_bytes", stdout.Len()),
zap.Int("stderr_bytes", stderr.Len()))
zap.Int64("stderr_bytes", stderr.ByteCount()))

if waitErr != nil {
// govulncheck.Cmd surfaces "exit status 3" (vulnerabilities
Expand All @@ -65,13 +72,7 @@ func (r libraryRunner) Run(ctx context.Context, moduleDir string) (RunnerResult,
}
return result, nil
}
// Surface stderr in the error message so build failures are
// debuggable from a single log line.
stderrPreview := truncateStderr(stderr.String(), 512)
if stderrPreview != "" {
return RunnerResult{}, fmt.Errorf("govulncheck failed: %w: %s", waitErr, stderrPreview)
}
return RunnerResult{}, fmt.Errorf("govulncheck failed: %w", waitErr)
return RunnerResult{}, fmt.Errorf("govulncheck failed: %w (stderr bytes: %d)", waitErr, stderr.ByteCount())
}

return parseGovulncheckJSON(stdout.Bytes())
Expand All @@ -97,11 +98,3 @@ func isVulnsFound(err error) bool {
}
return false
}

// truncateStderr returns at most n bytes of s with an ellipsis when truncated.
func truncateStderr(s string, n int) string {
if len(s) <= n {
return s
}
return s[:n] + "..."
}
3 changes: 0 additions & 3 deletions internal/analyzers/govulncheck/testdata_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -87,9 +87,6 @@ func TestGovulncheckDescriptorAndRunnerHelpers(t *testing.T) {
if isVulnsFound(errors.New("exit status 1")) || isVulnsFound(nil) {
t.Fatal("non-vulnerability errors must not match")
}
if got := truncateStderr("abcdef", 3); got != "abc..." {
t.Fatalf("truncateStderr = %q", got)
}
if got := NewRunner(nil).Name(); got != "library" {
t.Fatalf("runner name = %q, want library", got)
}
Expand Down
2 changes: 1 addition & 1 deletion internal/cli/benchmark_cmd.go
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@ func newBenchmarkCmd() *cobra.Command {
InstallFirst: installFirst,
Notifications: notifications,
Logger: logger,
NativeScan: benchmarkNativeScanner(logger, streams.notificationWriter(), current.Verbosity > 0),
NativeScan: benchmarkNativeScanner(logger, streams.notificationWriter(), current.Verbosity >= 2),
})
if renderErr := writeBenchmarkSummary(cmd, format, summary); renderErr != nil {
return renderErr
Expand Down
21 changes: 16 additions & 5 deletions internal/cli/benchmark_run.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,13 +17,14 @@ import (
"go.uber.org/zap"
)

func benchmarkNativeScanner(logger *zap.Logger, stderr io.Writer, verbose bool) benchmark.NativeScanFunc {
// benchmarkNativeScanner builds pipeline requests directly instead of going
// through Options.PipelineRequest, so it must apply the same subprocess-stderr
// gate: raw tool output is forwarded only at debug verbosity (-vv).
func benchmarkNativeScanner(logger *zap.Logger, stderr io.Writer, debug bool) benchmark.NativeScanFunc {
if logger == nil {
logger = zap.NewNop()
}
if stderr == nil {
stderr = io.Discard
}
stderr = benchmarkSubprocessStderr(stderr, debug)
return func(ctx context.Context, req benchmark.NativeScanRequest) (benchmark.NativeScanResult, error) {
checkoutDir, err := filepath.Abs(req.CheckoutDir)
if err != nil {
Expand Down Expand Up @@ -68,7 +69,7 @@ func benchmarkNativeScanner(logger *zap.Logger, stderr io.Writer, verbose bool)
DetectorFilter: detectorFilter,
InstallFirst: req.InstallFirst,
Stderr: stderr,
Verbose: verbose,
Verbose: debug,
})
if err != nil {
return benchmark.NativeScanResult{}, fmt.Errorf("run benchmark native scan: %w", err)
Expand Down Expand Up @@ -97,3 +98,13 @@ func benchmarkDetectorNames(results []sdk.DetectionResult) []string {
sort.Strings(names)
return names
}

// benchmarkSubprocessStderr mirrors the Options.PipelineRequest gate for
// pipeline requests that are built directly: raw subprocess stderr is
// forwarded only when debug verbosity (-vv) enabled it.
func benchmarkSubprocessStderr(stderr io.Writer, debug bool) io.Writer {
if !debug {
return nil
}
return stderr
}
9 changes: 9 additions & 0 deletions internal/cli/benchmark_run_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,15 @@ import (
"go.uber.org/zap"
)

func TestBenchmarkSubprocessStderrForwardsOnlyAtDebug(t *testing.T) {
if got := benchmarkSubprocessStderr(io.Discard, false); got != nil {
t.Fatalf("info-level stderr = %#v, want nil", got)
}
if got := benchmarkSubprocessStderr(io.Discard, true); got != io.Discard {
t.Fatalf("debug-level stderr = %#v, want the provided writer", got)
}
}

func TestBenchmarkNativeScannerUsesBomlyNativeDetector(t *testing.T) {
projectDir := t.TempDir()
lockfile := []byte(`{
Expand Down
8 changes: 4 additions & 4 deletions internal/cli/diff_resolve.go
Original file line number Diff line number Diff line change
Expand Up @@ -25,13 +25,13 @@ func resolveGitDiffGraphs(ctx context.Context, options *opts.Options, prog *prog
if repoCleanup != nil {
defer func() { _ = repoCleanup() }()
}
if err := git.VerifyRef(repoRoot, baseRef); err != nil {
if err := git.VerifyRef(logger, repoRoot, baseRef); err != nil {
return diffResolvedTarget{}, diffResolvedTarget{}, "", nil, nil, exit.InvalidInputError("verify --base %q: %v", baseRef, err)
}
if err := git.VerifyRef(repoRoot, headRef); err != nil {
if err := git.VerifyRef(logger, repoRoot, headRef); err != nil {
return diffResolvedTarget{}, diffResolvedTarget{}, "", nil, nil, exit.InvalidInputError("verify --head %q: %v", headRef, err)
}
changedLines, err := git.ChangedLineRanges(repoRoot, baseRef, headRef)
changedLines, err := git.ChangedLineRanges(logger, repoRoot, baseRef, headRef)
if err != nil && logger != nil {
logger.Warn("diff: changed line ranges unavailable", zap.Error(err))
}
Expand Down Expand Up @@ -76,7 +76,7 @@ func resolveDiffRepo(options *opts.Options, prog *progress.Progress, logger *zap
if err != nil {
return "", nil, "", err
}
repoRoot, err := git.FindRepoRoot(selectedPath)
repoRoot, err := git.FindRepoRoot(logger, selectedPath)
if err != nil {
return "", nil, "", exit.InvalidInputError("resolve local git repository: %v", err)
}
Expand Down
7 changes: 5 additions & 2 deletions internal/cli/opts/options.go
Original file line number Diff line number Diff line change
Expand Up @@ -118,6 +118,9 @@ func (o *Options) AnalyzerFilter() sdk.AnalyzerFilter {
func (o *Options) PipelineRequest(scope sdk.Scope, stderr io.Writer) engine.PipelineRequest {
failOn, _ := sdk.ParseFailOnList(o.ResolvedConfig.FailOn)
typosquatThreshold, _ := strconv.ParseFloat(strings.TrimSpace(o.ResolvedConfig.TyposquatThreshold), 64)
if !o.Verbose() {
stderr = nil
}
return engine.PipelineRequest{
ProjectPath: o.executionTarget.Location,
ExecutionTarget: o.executionTarget,
Expand Down Expand Up @@ -150,7 +153,7 @@ func (o *Options) PipelineRequest(scope sdk.Scope, stderr io.Writer) engine.Pipe
}
}

// Verbose reports whether verbose command output is enabled.
// Verbose reports whether debug-level subprocess output is enabled.
func (o *Options) Verbose() bool {
return o.verbose
}
Expand Down Expand Up @@ -363,7 +366,7 @@ func (o *Options) PrepareForExecutionTarget(ctx context.Context, logger *zap.Log
httpProvider: httpProvider,
ResolvedConfig: resolved,
Format: format,
verbose: resolved.Verbosity > 0,
verbose: resolved.Verbosity >= 2,
cleanup: cleanup,
findingPolicyResolvers: baselineResult.Resolvers,
baselineEvaluation: baselineEvaluationFromLoadResult(baselineResult),
Expand Down
17 changes: 17 additions & 0 deletions internal/cli/opts/options_test.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package opts

import (
"bytes"
"context"
"os"
"path/filepath"
Expand Down Expand Up @@ -28,6 +29,22 @@ func TestCommandContextRoundTripsThroughContext(t *testing.T) {
}
}

func TestPipelineRequestExposesSubprocessStderrOnlyAtDebug(t *testing.T) {
var stderr bytes.Buffer

infoOptions := Options{verbose: false}
info := infoOptions.PipelineRequest(sdk.ScopeUnknown, &stderr)
if info.Stderr != nil || info.Verbose {
t.Fatalf("info request enabled subprocess stderr: %#v", info)
}

debugOptions := Options{verbose: true}
debug := debugOptions.PipelineRequest(sdk.ScopeUnknown, &stderr)
if debug.Stderr != &stderr || !debug.Verbose {
t.Fatalf("debug request did not enable subprocess stderr: %#v", debug)
}
}

func TestCommandContextResolveExecutionTarget_Image(t *testing.T) {
options := Options{ResolvedConfig: config.Resolved{Image: "alpine:3.20"}}

Expand Down
5 changes: 3 additions & 2 deletions internal/cli/root_cmd.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (

"github.com/bomly-dev/bomly-cli/internal/cli/exit"
"github.com/bomly-dev/bomly-cli/internal/cli/opts"
"github.com/bomly-dev/bomly-cli/internal/logging"
"github.com/spf13/cobra"
"github.com/spf13/pflag"
"go.uber.org/zap"
Expand Down Expand Up @@ -201,7 +202,7 @@ func logResolvedOptions(cmd *cobra.Command) {
logger.Debug("Resolved options",
zap.String("path", resolved.Path),
zap.String("image", resolved.Image),
zap.String("url", resolved.URL),
zap.String("url", logging.SanitizeURL(resolved.URL)),
zap.String("ref", resolved.Ref),
zap.Bool("sbom", resolved.SBOM),
zap.Bool("enrich", resolved.Enrich),
Expand All @@ -215,7 +216,7 @@ func logResolvedOptions(cmd *cobra.Command) {
zap.String("ecosystems", resolved.Ecosystems),
zap.String("detectors", resolved.Detectors),
zap.Bool("install_first", resolved.InstallFirst),
zap.Strings("install_args", resolved.InstallArgs),
zap.Strings("install_args", logging.SanitizeArgs(resolved.InstallArgs)),
zap.String("config", resolved.Config),
zap.Bool("verbose", resolved.Verbosity > 0),
zap.Int("verbosity", resolved.Verbosity),
Expand Down
21 changes: 19 additions & 2 deletions internal/cli/root_cmd_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import (
"bytes"
"encoding/json"
"fmt"
"io"
"os"
"os/exec"
"path/filepath"
Expand Down Expand Up @@ -2652,12 +2653,28 @@ func TestRoot_ScanCommand_MavenMissingJavaReturnsResolutionFailure(t *testing.T)
if got := exit.Code(err); got != 3 {
t.Fatalf("expected resolution failure exit code 3, got %d (err=%v)", got, err)
}
if !strings.Contains(err.Error(), "Unable to locate a Java Runtime") {
t.Fatalf("expected Java runtime message in error, got %v", err)
if !strings.Contains(err.Error(), "diagnostic bytes:") ||
strings.Contains(err.Error(), "Unable to locate a Java Runtime") {
t.Fatalf("expected secret-safe Java runtime message in error, got %v", err)
}
if stdout.Len() != 0 {
t.Fatalf("expected no stdout on resolution failure, got %q", stdout.String())
}

debugRoot, err := newRootCmd("0.9.0-test")
if err != nil {
t.Fatalf("newRootCmd() debug error = %v", err)
}
var debugStderr bytes.Buffer
debugRoot.SetOut(io.Discard)
debugRoot.SetErr(&debugStderr)
debugRoot.SetArgs([]string{"scan", "--path", projectDir, "--ecosystems", "maven", "--detectors", "maven-detector", "--format", "json", "-vv"})
if err := debugRoot.Execute(); err == nil {
t.Fatal("expected debug scan to fail when Java is unavailable")
}
if !strings.Contains(debugStderr.String(), "Unable to locate a Java Runtime") {
t.Fatalf("expected Java diagnostics in debug output, got %q", debugStderr.String())
}
}

func TestRoot_WhyCommand_GoModules_JSONOutput(t *testing.T) {
Expand Down
9 changes: 7 additions & 2 deletions internal/detectors/cargo/detector.go
Original file line number Diff line number Diff line change
Expand Up @@ -129,8 +129,8 @@ func (d Detector) ResolveGraph(_ context.Context, req sdk.DetectionRequest) (sdk
raw, err := cmd.Output()
if err != nil {
fields := []zap.Field{zap.Error(err)}
if commandStderr.String() != "" {
fields = append(fields, zap.String("stderr", commandStderr.String()))
if commandStderr.ByteCount() > 0 {
fields = append(fields, zap.Int64("stderr_bytes", commandStderr.ByteCount()))
}
logger.Debug("cargo detector failure details", fields...)
return sdk.DetectionResult{}, fmt.Errorf("run cargo metadata: %w", err)
Expand Down Expand Up @@ -650,6 +650,10 @@ func trimTomlString(value string) string {

// Install prepares Cargo dependencies before graph resolution.
func (d Detector) Install(_ context.Context, req sdk.DetectionRequest) error {
logger := d.Logger
if logger == nil {
logger = zap.NewNop()
}
cargoPath, err := cargoExecLookPath("cargo")
if err != nil {
return fmt.Errorf("resolve cargo executable: %w", err)
Expand All @@ -658,6 +662,7 @@ func (d Detector) Install(_ context.Context, req sdk.DetectionRequest) error {
cmd := cargoExecCommand(cargoPath, args...)
cmd.Dir = d.workingDir(req.ProjectPath)
cmd.Stderr = logging.NewCommandStderr(req.Stderr, req.Verbose)
logger.Debug("running cargo detector install-first", logging.CommandFields(cargoPath, args, cmd.Dir)...)
if err := cmd.Run(); err != nil {
return fmt.Errorf("run cargo fetch: %w", err)
}
Expand Down
6 changes: 3 additions & 3 deletions internal/detectors/composer/detector.go
Original file line number Diff line number Diff line change
Expand Up @@ -126,11 +126,11 @@ func (d Detector) Install(_ context.Context, req sdk.DetectionRequest) error {

started := time.Now()
logger.Info("Composer detector running install-first step")
logger.Debug("running composer detector install-first", zap.String("working_dir", cmd.Dir), zap.String("executable", composerPath), zap.Strings("args", args))
logger.Debug("running composer detector install-first", logging.CommandFields(composerPath, args, cmd.Dir)...)
if err := cmd.Run(); err != nil {
fields := []zap.Field{zap.Error(err)}
if commandStderr.String() != "" {
fields = append(fields, zap.String("stderr", commandStderr.String()))
if commandStderr.ByteCount() > 0 {
fields = append(fields, zap.Int64("stderr_bytes", commandStderr.ByteCount()))
}
logger.Debug("composer detector install-first failure details", fields...)
return fmt.Errorf("run composer install: %w", err)
Expand Down
Loading