feat(#51): add --verbose flag for debug output - #143
Conversation
…low CLI Add a `--verbose` / `-v` flag to `npm run full` that emits detailed debug output to stderr: configuration, parsed ticket, model, development options, and phase timing. Normal stdout output is unchanged when the flag is absent. - New reusable `src/utils/debug-logger.ts`: a small logger that writes to stderr, redacts secrets (sk-ant-/sk- keys, Bearer/Authorization headers, api_key/token/secret/password key-values), and truncates long payloads. Sink and clock are injectable for testing. - New `src/cli/full-args.ts`: position-independent flag/ticket-path parsing, split from the CLI entry so it is unit-testable without running the workflow. - Wire the flag into `src/cli/full.ts`; guard the auto-run with `require.main === module` so importing it in tests has no side effects. - Docs: README section + updated CLI header/usage. Tests: redaction (each secret class), truncation, logger enable/disable, JSON/circular payloads, injected-clock timing, and arg parsing.
44f9628 to
31e6392
Compare
sugat009
left a comment
sugat009
left a comment
There was a problem hiding this comment.
Nice piece of work. The logger's shape is genuinely good: injectable sink and clock, redaction ordered before truncation, a shared no-op for the disabled path, and splitting parseCliArgs into its own module specifically so it is testable without importing the CLI entrypoint. The require.main === module guard is the right instinct too. 21 new tests, suite at 1022 from a 1001 baseline, tsc and eslint clean.
One blocking problem, and it is the invocation rather than the code: npm run full <ticket> --verbose, the only form the README documents, does not enable verbose mode. --verbose is npm's own flag, so npm consumes it instead of forwarding it, and -v makes npm print its version and never run the workflow at all. I verified both with an argv probe rather than inferring it; details inline. The parser is fine, so this is a one-line docs fix plus a decision about -v.
The rest is redaction hardening. I attacked the five patterns with a corpus of real key shapes, and the one that matters for this repo is sk-: the rule written for OpenAI-style keys omits - and _ from its character class, so sk-or-v1-... (OpenRouter, which is in this repo's .env.example and drives the memory pipeline) and sk-proj-... both pass straight through.
Worth being fair about severity on all of that: none of the current debug.log call sites carry a secret. They log a filesystem path, ticket title/type/domain, a model name, developmentOptions, and two booleans. So today these are defence-in-depth gaps, not live leaks. They become real the moment the logger is wired into LLM prompt/response logging, which your scope note says is next, and that is exactly why I would rather fix them now than after.
On scope: "Closes #51" will auto-close the issue while most of its "what to log" list is still unimplemented. Your scope note is clear about that, so this is just a suggestion to change it to "Refs #51" and leave the ticket open for the wiring.
| it is safe to share. Normal stdout output is unchanged. | ||
|
|
||
| ```bash | ||
| npm run full tickets/my-ticket.md --verbose |
There was a problem hiding this comment.
issue (blocking): this is the only documented way to use the feature, and it does not enable verbose mode. --verbose collides with npm's own flag, so npm consumes it and never forwards it to the script. I verified it with an argv probe in a worktree:
$ npm run <script> tickets/x.md --verbose
npm verbose cli /home/.../node .../npm <- npm turned ITS OWN verbose logging on
npm verbose title npm run <script> tickets/x.md <- flag stripped from the script's args
$ npm run <script> tickets/x.md -- --verbose
argv: ["tickets/x.md","--verbose"] <- works, needs the -- separator
The irony is that it looks like it worked, because npm starts printing its own verbose output.
-v is worse. npm reads it as --version:
$ npm run <script> -v
11.12.1 <- printed npm's version, never ran the script
Suggest documenting npm run full <ticket> -- --verbose, and either dropping -v or noting it cannot work through npm run. parseCliArgs itself is fine; this is purely the invocation.
|
|
||
| ### Verbose debug output | ||
|
|
||
| Pass `--verbose` (or `-v`) to the full workflow CLI to emit detailed debug |
There was a problem hiding this comment.
issue (non-blocking): same collision applies to the -v alias mentioned here. Also, "secrets are redacted" is unqualified: the redactor covers sk-ant- keys, some sk- keys, Authorization/Bearer headers, and api_key/token/secret/password pairs. It does not cover GitHub PATs, AWS keys, JWTs, or credentials embedded in connection strings, and it does not redact the log label at all (see the note on debug-logger.ts:106). Worth softening, since "safe to share" is the sort of line someone acts on.
| // Anthropic-style API keys: sk-ant-... | ||
| .replace(/sk-ant-[A-Za-z0-9_-]{6,}/g, 'sk-ant-***REDACTED***') | ||
| // Other `sk-` prefixed keys (e.g. OpenAI): sk-<long token> | ||
| .replace(/sk-[A-Za-z0-9]{16,}/g, 'sk-***REDACTED***') |
There was a problem hiding this comment.
issue (non-blocking): this rule is documented as covering "Other sk- prefixed keys (e.g. OpenAI)" but its character class omits - and _, unlike the sk-ant- rule directly above it which includes both. So the modern key shapes pass through untouched. Verified against the patterns directly:
sk-proj-AbC123def456GHI789jkl012MNO -> unredacted (OpenAI, current format)
sk-or-v1-abc123def456ghi789jkl -> unredacted (OpenRouter)
sk-ant-api03-AbC123_xy-ZZ99001122334455 -> redacted correctly
OpenRouter matters here specifically: OPENROUTER_API_KEY is in this repo's .env.example and drives the memory pipeline. Adding _- to the class fixes all three.
| .replace(/Bearer\s+[A-Z0-9._-]{8,}/gi, 'Bearer ***REDACTED***') | ||
| // key/value pairs: apiKey / api_key / token / secret / password | ||
| .replace( | ||
| /("?(?:api[_-]?key|apikey|token|secret|password)"?\s*[:=]\s*)("?)([^"\s,}]{4,})\2/gi, |
There was a problem hiding this comment.
issue (non-blocking): the \2 backreference makes this fail open on the values most likely to need redacting. Because group 2 captures the opening quote and must match again at the end, a quoted secret containing a space, comma or brace does not match at all, so it gets zero redaction rather than partial. An unquoted value stops at the first space. Suggest dropping the backreference and handling quoted and unquoted forms as separate alternatives.
| // Authorization headers: redact the whole credential (scheme + token), so | ||
| // both "Bearer <jwt>" and "Basic <base64>" forms are covered. Runs before | ||
| // the standalone Bearer rule so the credential is redacted exactly once. | ||
| .replace(/(authorization"?\s*[:=]\s*"?)[^"\n,}]{4,}/gi, '$1***REDACTED***') |
There was a problem hiding this comment.
issue (non-blocking): this rule (and the key-name rule below) operates on the raw string, but formatData feeds it JSON.stringify output, where a nested object serialised inside a string value has its quotes escaped as \". The "? in the pattern does not match \", so secrets one level deep in a stringified-JSON-inside-JSON payload are missed. Worth a test with a doubly-encoded payload, since LLM request/response objects often carry one.
| export function createDebugLogger(options: DebugLoggerOptions): DebugLogger { | ||
| if (!options.enabled) return NOOP_LOGGER; | ||
| const maxLength = options.maxLength ?? DEFAULT_MAX_LENGTH; | ||
| const sink = options.sink ?? ((line: string) => process.stderr.write(line)); |
There was a problem hiding this comment.
issue (non-blocking): no test proves output goes to stderr. Every spec injects the sink option, so switching this default to process.stdout.write would leave the suite green, and stderr-routing is the module's first stated design goal. One test asserting the default sink writes to process.stderr would lock it in.
| const now = options.now ?? Date.now; | ||
|
|
||
| const log = (label: string, data?: unknown): void => { | ||
| sink(`[debug] ${label}${renderSuffix(data, maxLength)}\n`); |
There was a problem hiding this comment.
issue (non-blocking): the label is interpolated raw, so it is neither redacted nor truncated, while the module docstring says sensitive data is redacted "before it is ever written" and the README calls the output safe to share. A caller doing debug.log(request to ${url}) with a credentialed URL leaks it. Cheap fix: run the label through redactSensitive too.
| /** Truncate long text, appending a marker with the original length. */ | ||
| export function truncate(text: string, maxLength: number = DEFAULT_MAX_LENGTH): string { | ||
| if (text.length <= maxLength) return text; | ||
| return `${text.slice(0, maxLength)}… (${text.length} chars total)`; |
There was a problem hiding this comment.
nitpick: the (N chars total) marker reports the post-redaction length, since truncate runs after redactSensitive, so the number misstates the real payload size whenever anything was redacted. Minor, but the marker exists precisely to tell you what you lost.
| ticket, | ||
| developmentOptions | ||
| ); | ||
| stopTimer(); |
There was a problem hiding this comment.
suggestion (non-blocking): stopTimer() sits on the success path only, so a workflow that throws logs no duration, which is the run where timing matters most. try { ... } finally { stopTimer(); } would cover both.
| */ | ||
| export function parseCliArgs(argv: string[]): CliArgs { | ||
| const args = argv.slice(2); | ||
| const verbose = args.includes('--verbose') || args.includes('-v'); |
There was a problem hiding this comment.
nitpick: args.find(a => !a.startsWith('-')) takes the first non-dash token as the ticket, so a near-miss spelling like --verbos is silently ignored (verbose just stays off), and any future flag taking a separate value would have its value swallowed as the ticket path. Fine for today's single boolean flag; worth a comment noting the assumption.
2 participants
Summary
Closes #51.
Adds a
--verbose/-vflag to the full-workflow CLI (npm run full) that emits detailed debug output to stderr. Normal stdout output is unchanged when the flag is absent.What it logs
At the CLI boundary: verbose-mode notice, cht-core path, parsed ticket (title/type/domain), configured model, development options, full-workflow timing, and a completion summary. All payloads are redacted + truncated before writing.
Design
src/utils/debug-logger.ts— small reusable logger:sk-ant-/sk-keys,Bearer+Authorizationheaders, andapi_key/token/secret/passwordkey-value pairs (linear-time patterns, no ReDoS)src/cli/full-args.ts— position-independent flag/ticket parsing, split out so it is unit-testable without importing the CLI entry (which runs the workflow). Also fixes a latent bug where a flag in the first positional slot was treated as the ticket path.src/cli/full.ts— wires the flag in and guards the auto-run withrequire.main === module.Scope note
This covers the flag, stderr routing, redaction/truncation, and CLI-level lifecycle + timing logging. Deeper per-LLM-call prompt/response/token logging (listed aspirationally in the issue) is a natural follow-up that can reuse this same logger — kept out here to keep the change focused and the diff reviewable.
Acceptance criteria
--verboseflag implementedTest plan
npm run build— cleannpm run lint— cleannpm test— 1032 passing (+21 new: 15 logger, 6 arg-parsing)npm run test:coverage— all floors pass;debug-logger.ts96% stmts,full-args.ts100%