Merge pull request #50 from link-assistant/issue-49-bef878bb5d38

Fix: Suppress debug output in CLI commands unless --verbose is used

Author: konard

.changeset/fix-debug-output-in-cli.md

@@ -0,0 +1,5 @@
+---
+'@link-assistant/agent': patch
+---
+
+Fix debug output appearing in CLI commands - logs are now suppressed by default and only shown with --verbose flag. This fixes the issue where commands like `agent auth list` displayed debug messages that broke the clean CLI UI.

docs/case-studies/issue-49/issue-data.json

@@ -0,0 +1,23 @@
+{
+  "author": {
+    "id": "MDQ6VXNlcjE0MzE5MDQ=",
+    "is_bot": false,
+    "login": "konard",
+    "name": "Konstantin Diachenko"
+  },
+  "body": "```\nkonard@MacBook-Pro-Konstantin ~ % agent auth list                                      \n\n┌  Credentials ~/.local/share/opencode/auth.json\nINFO  2025-12-16T12:43:13 +38ms service=models.dev file={} refreshing\n│\n●  Anthropic oauth\n│\n└  1 credentials\n\nkonard@MacBook-Pro-Konstantin ~ %    \n```\n\nDebug output detected:\n\n```\nINFO  2025-12-16T12:43:13 +38ms service=models.dev file={} refreshing\n```\n\nThe debug output should only be shown when --verbose option is provided.\n\nPlease make sure we double check all similar places for all types of CLI input for `agent` command.\n\nPlease download all logs and data related about the issue to this repository, make sure we compile that data to `./docs/case-studies/issue-{id}` folder, and use it to do deep case study analysis (also make sure to search online for additional facts and data), in which we will reconstruct timeline/sequence of events, find root causes of the problem, and propose possible solutions.",
+  "comments": [],
+  "createdAt": "2025-12-16T12:46:08Z",
+  "labels": [
+    {
+      "id": "LA_kwDOQYTy3M8AAAACQHoi-w",
+      "name": "bug",
+      "description": "Something isn't working",
+      "color": "d73a4a"
+    }
+  ],
+  "number": 49,
+  "state": "OPEN",
+  "title": "By default no there in the CLI we should have not have any debug output that breaks CLI UI",
+  "updatedAt": "2025-12-16T12:46:08Z"
+}

docs/case-studies/issue-49/pr-data.json

@@ -0,0 +1,16 @@
+{
+  "author": {
+    "id": "MDQ6VXNlcjE0MzE5MDQ=",
+    "is_bot": false,
+    "login": "konard",
+    "name": "Konstantin Diachenko"
+  },
+  "baseRefName": "main",
+  "body": "## 🤖 AI-Powered Solution Draft\n\nThis pull request is being automatically generated to solve issue #49.\n\n### 📋 Issue Reference\nFixes #49\n\n### 🚧 Status\n**Work in Progress** - The AI assistant is currently analyzing and implementing the solution draft.\n\n### 📝 Implementation Details\n_Details will be added as the solution draft is developed..._\n\n---\n*This PR was created automatically by the AI issue solver*",
+  "createdAt": "2025-12-16T12:49:42Z",
+  "headRefName": "issue-49-bef878bb5d38",
+  "number": 50,
+  "state": "OPEN",
+  "title": "[WIP] By default no there in the CLI we should have not have any debug output that breaks CLI UI",
+  "updatedAt": "2025-12-16T12:49:43Z"
+}

docs/case-studies/issue-49/research.md

@@ -0,0 +1,77 @@
+# CLI Debug Logging Best Practices Research
+
+## Sources
+
+### Stderr vs Stdout Separation
+
+- [Configuring CLI output verbosity with logging and argparse](https://xahteiwi.eu/resources/hints-and-kinks/python-cli-logging-options/)
+- [The CLI's Essential '—Verbose' Option - Dojo Five](https://dojofive.com/blog/the-clis-essential-verbose-option/)
+
+### Verbose Flag Implementation
+
+- [Verbose Logging](https://medium.com/@pooja_virani/verbose-logging-a60cccb3eb66)
+- [Go Flags: Beyond the Basics](https://dzone.com/articles/go-flags-beyond-the-basics)
+
+### Debug Output and User Experience
+
+- [Debugging - Better CLI](https://bettercli.org/design/debugging/)
+- [Mastering CLI Design: Best Practices](https://jsschools.com/programming/mastering-cli-design-best-practices-for-powerful-/)
+
+## Key Best Practices
+
+### 1. Stderr vs Stdout Separation
+
+Log output that tells users about what the program is doing should go to stderr, while output related to the program's results goes to stdout, giving users the ability to pipe stdout without interference.
+
+### 2. Verbose Flag Implementation
+
+By default, CLIs should log only warnings and errors to stderr, but when debugging issues, enable more verbose logging by passing a --verbose flag. Common patterns include:
+
+- Using `-v` for INFO level and `-vv` for DEBUG level
+- Verbose logging with `-v` flag, with log levels between 1 and 11 for increasing verbosity
+
+### 3. Default Behavior
+
+Events of severity WARNING and greater should be printed to sys.stderr by default, which is regarded as the best default behavior.
+
+### 4. Quiet Mode
+
+Also define a `-q` or `--quiet` option that suppresses warnings and shows only errors.
+
+### 5. Output Guidelines
+
+Keep reporting short and sweet, especially on successful runs - only mention important parts, and be descriptive but short.
+
+### 6. Debug Mode for Programs
+
+Debug log messages from your program are hidden by default, but can be shown using the `-d` or `--debug` flag.
+
+### 7. Standard Debug Flags
+
+CLI tools commonly provide flags like -d/--debug, -v/--verbose, DEBUG environment variable or similar debugging options, and these flags should be implemented as global options, meaning they could be used in any command and in any combination.
+
+### 8. Conditional Debug Output for Better UX
+
+When handling errors in CLI tools, you can conditionally show detailed information: if debug mode is enabled, display full traceback information; otherwise, show a simple error message and suggest running with --debug for details. This approach prevents overwhelming users with technical output during normal operation while still making debugging information accessible when needed.
+
+### 9. Impact on User Experience
+
+How your CLI presents information significantly impacts user experience. Debug output can create challenges:
+
+- **Console flooding**: Debug messages can overload the console, making it difficult to use the CLI effectively
+- **Performance impact**: Enabling debugging can disrupt operation when systems are experiencing high load conditions
+- **Usability issues**: Without proper controls, debug output can make tools difficult to use in production environments
+
+### 10. Recommendations
+
+The key is to keep debug output disabled by default and provide explicit flags for users who need it, ensuring that regular users enjoy a clean, focused experience while developers and troubleshooters can access detailed information when necessary.
+
+## Application to Agent CLI
+
+Based on these best practices, the Agent CLI should:
+
+1. **Suppress all INFO/DEBUG logs by default** - Only show warnings and errors
+2. **Enable verbose logging with --verbose flag** - Show INFO/DEBUG when explicitly requested
+3. **Initialize logging early** - Before any commands execute, initialize the logging system
+4. **Use log files for background operations** - Write non-critical logs to files instead of stderr
+5. **Keep CLI output clean** - Only show user-relevant information by default

docs/case-studies/issue-49/root-cause-analysis.md

@@ -0,0 +1,179 @@
+# Root Cause Analysis: Debug Output Breaking CLI UI
+
+## Issue Summary
+
+When running `agent auth list`, the command outputs debug logging information that breaks the CLI user interface:
+
+```
+INFO  2025-12-16T12:43:13 +38ms service=models.dev file={} refreshing
+```
+
+This debug output should only be shown when the `--verbose` flag is provided.
+
+## Root Cause Analysis
+
+### The Problem Chain
+
+1. **Default Logging Behavior (src/util/log.ts:55)**
+
+   ```typescript
+   let write = (msg: any) => Bun.stderr.write(msg);
+   ```
+
+   - By default, all log messages write directly to `stderr`
+   - This happens **before** `Log.init()` is called
+   - The default log level is `INFO` (line 19)
+
+2. **Missing Log Initialization for CLI Commands**
+   - **Agent mode** (src/index.js:182-185): Properly calls `Log.init()`
+   - **Run command** (src/cli/cmd/run.ts:115): Properly calls `Log.init()`
+   - **Auth commands**: **NEVER** calls `Log.init()`
+   - **Other CLI commands (mcp, models, stats, export, etc.)**: Also don't call `Log.init()`
+
+3. **Early Logger Creation (src/provider/models.ts:8)**
+
+   ```typescript
+   const log = Log.create({ service: 'models.dev' });
+   ```
+
+   - Logger is created at module import time
+   - Uses default `write` function pointing to `stderr`
+   - Any calls to `log.info()` will output to stderr by default
+
+4. **Auth List Command Flow**
+
+   **Call Chain:**
+
+   ```
+   user runs: agent auth list
+   ↓
+   src/index.js:519 → AuthCommand is invoked
+   ↓
+   src/cli/cmd/auth.ts:26 → AuthListCommand.handler()
+   ↓
+   src/cli/cmd/auth.ts:35 → ModelsDev.get() is called
+   ↓
+   src/provider/models.ts:71 → refresh() is called
+   ↓
+   src/provider/models.ts:81 → log.info('refreshing', { file })
+   ↓
+   PROBLEM: write() still points to Bun.stderr.write()
+   ↓
+   Debug output appears in CLI: "INFO 2025-12-16T12:43:13 +38ms service=models.dev file={} refreshing"
+   ```
+
+5. **Why Log.init() Matters**
+
+   When `Log.init({ print: false })` is called (src/util/log.ts:57-75):
+
+   ```typescript
+   export async function init(options: Options) {
+     if (options.level) level = options.level;
+     cleanup(Global.Path.log);
+     if (options.print) return;  // If print=true, keep using stderr
+
+     // Create log file path
+     logpath = path.join(Global.Path.log, ...);
+     const logfile = Bun.file(logpath);
+     const writer = logfile.writer();
+
+     // REDIRECT write function to log file instead of stderr
+     write = async (msg: any) => {
+       const num = writer.write(msg);
+       writer.flush();
+       return num;
+     };
+   }
+   ```
+
+   **Before Log.init()**: `write` → `Bun.stderr.write()` ✗ visible in CLI
+   **After Log.init({ print: false })**: `write` → `logfile.writer()` ✓ hidden in log file
+
+### Timeline of Events
+
+1. **User runs command**: `agent auth list`
+2. **Module imports happen**:
+   - `src/provider/models.ts` is imported
+   - Line 8: `const log = Log.create({ service: 'models.dev' })` executes
+   - Logger is created with default `write = Bun.stderr.write`
+3. **yargs parses command**: Identifies `auth list` subcommand
+4. **Command handler executes**: `AuthListCommand.handler()` at line 26
+5. **Models are fetched**: Line 35 calls `ModelsDev.get()`
+6. **Refresh is triggered**: Line 71 calls `refresh()`
+7. **Log output occurs**: Line 81 calls `log.info('refreshing', { file })`
+8. **Output goes to stderr**: Because `Log.init()` was never called
+9. **User sees debug output**: Breaking the clean CLI UI
+
+### Additional Issues
+
+**Background Refresh Timer (src/provider/models.ts:98)**
+
+```typescript
+setInterval(() => ModelsDev.refresh(), 60 * 1000 * 60).unref();
+```
+
+This timer runs every 60 minutes in the background and will also output to stderr if `Log.init()` hasn't been called, potentially interrupting long-running processes or piped output.
+
+## Affected Commands
+
+Based on analysis, the following CLI commands are affected (they don't initialize logging):
+
+1. **auth** commands:
+   - `agent auth list` ✗
+   - `agent auth login` ✗
+   - `agent auth logout` ✗
+   - `agent auth status` ✗
+
+2. **mcp** commands (src/cli/cmd/mcp.ts):
+   - `agent mcp list` ✗
+   - `agent mcp install` ✗
+   - Any logging in MCP operations will leak to stderr
+
+3. **models** commands (src/cli/cmd/models.ts):
+   - Any model-related operations ✗
+
+4. **stats** commands (src/cli/cmd/stats.ts):
+   - Any stats operations ✗
+
+5. **export** commands (src/cli/cmd/export.ts):
+   - Any export operations ✗
+
+**Not Affected:**
+
+- `agent` (default mode) ✓ - Calls Log.init() at line 182
+- `agent run` ✓ - Calls Log.init() at line 115 (when verbose)
+
+## Why This Violates Best Practices
+
+According to CLI best practices research:
+
+1. **Default Behavior**: CLIs should only show warnings and errors by default
+2. **Verbose Flag**: INFO/DEBUG logs should only appear with `--verbose` flag
+3. **Clean Output**: Regular users should enjoy a clean, focused experience
+4. **Stderr vs Stdout**: Debug output mixing with command output disrupts piping and scripting
+
+The current behavior violates all of these principles for CLI commands that don't initialize logging.
+
+## Solution Requirements
+
+To fix this issue, we need to:
+
+1. **Initialize logging early** for ALL CLI commands, not just agent mode
+2. **Respect the verbose flag** - Only print to stderr when `--verbose` is used
+3. **Default to file logging** - Write logs to files by default (not stderr)
+4. **Ensure consistency** - All commands should have the same logging behavior
+5. **Maintain backward compatibility** - Don't break existing verbose flag behavior
+
+## Proposed Solution
+
+Add a global middleware or initialization in `src/index.js` that:
+
+- Calls `Log.init({ print: false })` before any commands execute
+- Allows `--verbose` flag to enable `Log.init({ print: true, level: 'DEBUG' })`
+- Applies to ALL commands, not just agent mode
+
+This ensures:
+
+- By default: logs go to files in `~/.local/share/opencode/log/`
+- With `--verbose`: logs print to stderr for debugging
+- Clean CLI UI for all commands without debug pollution