|
| 1 | +--- |
| 2 | +id: 18 |
| 3 | +summary: "Add --debug flag for HTTP request/response logging with credential redaction, restructure log levels across CLI and TUI" |
| 4 | +created: 2026-03-11 |
| 5 | +--- |
| 6 | + |
| 7 | +# Plan: HTTP Debug Logging with Credential Redaction |
| 8 | + |
| 9 | +## Original Work Order |
| 10 | +> Extend debug logging to show HTTP requests and responses, redacting keys, tokens, and credentials. The CLI / TUI tools should have `--verbose`, which is the existing behaviour (rename the help text to `Enable verbose logging`). Then, we should have a `--debug` parameter which is "Enable verbose logging including HTTP requests and responses". Internally, --verbose should map to an info log level, and --debug should map to a debug log level. With nothing specified, our log level should default to warn. |
| 11 | +
|
| 12 | +## Plan Clarifications |
| 13 | + |
| 14 | +| Question | Answer | |
| 15 | +|---|---| |
| 16 | +| There are currently zero `_LOGGER.info()` calls in the codebase. `--verbose` (INFO) would produce no additional output vs default (WARNING). Should some existing DEBUG messages be promoted to INFO? | Yes. Promote `client.py`'s request summary line (`"GET /url -> 200"`) and key `auth.py` lifecycle messages (silent token acquisition, auth success) to INFO. Keep `protocol.py` decode/encode detail and full HTTP request/response traces at DEBUG. | |
| 17 | + |
| 18 | +## Executive Summary |
| 19 | + |
| 20 | +The library already has partial HTTP debug logging in `b2c_login.py` (via `_log_request`/`_log_response` helpers) but the main API client in `client.py` only logs a one-line summary at DEBUG level. Meanwhile, the `--verbose` flag currently maps directly to DEBUG, providing no intermediate INFO level. Additionally, there are zero INFO-level log calls in the entire codebase, so the intermediate tier would be invisible without re-leveling some messages. |
| 21 | + |
| 22 | +This plan restructures the logging tiers so `--verbose` gives INFO-level insight (request summaries, auth lifecycle) while `--debug` unlocks full HTTP request/response tracing. The HTTP tracing in `client.py._request` will follow the same pattern already established in `b2c_login.py`, with a shared redaction utility to mask Bearer tokens, passwords, CSRF tokens, and other credentials before they reach the log output. Select existing DEBUG messages in `client.py` and `auth.py` will be promoted to INFO to populate the verbose tier. |
| 23 | + |
| 24 | +## Context |
| 25 | + |
| 26 | +### Current State vs Target State |
| 27 | + |
| 28 | +| Current State | Target State | Why? | |
| 29 | +|---|---|---| |
| 30 | +| `--verbose` maps to DEBUG | `--verbose` maps to INFO | Provides a useful middle ground without overwhelming HTTP detail | |
| 31 | +| No `--debug` flag exists | `--debug` maps to DEBUG | Unlocks full HTTP request/response tracing for troubleshooting | |
| 32 | +| Default log level is WARNING | Default log level remains WARNING | No change needed | |
| 33 | +| Help text says "Enable debug logging" | Help text says "Enable verbose logging" / "Enable verbose logging including HTTP requests and responses" | Accurate description of each flag's purpose | |
| 34 | +| Zero `_LOGGER.info()` calls exist | Key messages in `client.py` and `auth.py` promoted to INFO | Makes `--verbose` produce useful output | |
| 35 | +| `client.py._request` logs only `"GET /url -> 200"` at DEBUG | Summary line promoted to INFO; full headers/body logged at DEBUG | INFO gives request-level trace; DEBUG gives full HTTP detail | |
| 36 | +| `b2c_login.py` has its own `_log_request`/`_log_response` | Shared helpers in `_http_logging.py` used by both modules | Consistent redaction of sensitive values | |
| 37 | +| `b2c_login._log_request` redacts only `password` key in form data | Redaction covers Authorization headers, passwords, CSRF tokens, and cookie values | Prevents accidental credential leakage in logs | |
| 38 | +| TUI `run_tui(verbose=bool)` sets DEBUG on verbose | TUI accepts a `log_level: int` and applies it directly | Supports both verbose and debug modes | |
| 39 | + |
| 40 | +### Background |
| 41 | + |
| 42 | +The `b2c_login.py` module already contains a well-structured pattern for HTTP debug logging (`_log_request` at line 117, `_log_response` at line 136). These use `>>>` and `<<<` prefixes and truncate response bodies to 2000 characters. The `client.py._request` method (line 135) is the single point through which all API calls flow, making it the ideal place to add equivalent tracing. The `b2c_login.py` redaction currently only masks the `password` form field; Bearer tokens in Authorization headers and CSRF tokens are logged in plain text. |
| 43 | + |
| 44 | +The existing DEBUG messages across the codebase fall into three categories: |
| 45 | +- **Auth lifecycle** (`auth.py`): "Attempting silent token acquisition", "Token acquired silently", "Authentication successful" — useful operational context, appropriate for INFO. |
| 46 | +- **Request summary** (`client.py`): `"GET /url -> 200"` — useful at INFO to see API traffic without full payloads. |
| 47 | +- **Protocol decode/encode** (`protocol.py`): Byte-level parameter decoding — noisy, should remain at DEBUG. |
| 48 | + |
| 49 | +## Architectural Approach |
| 50 | + |
| 51 | +```mermaid |
| 52 | +flowchart TD |
| 53 | + CLI["CLI / TUI entry point"] |
| 54 | + CLI -->|"--debug"| DEBUG["logging.DEBUG"] |
| 55 | + CLI -->|"--verbose"| INFO["logging.INFO"] |
| 56 | + CLI -->|"(default)"| WARN["logging.WARNING"] |
| 57 | +
|
| 58 | + INFO --> SUMMARY["client.py: request summary line\nauth.py: lifecycle messages"] |
| 59 | + DEBUG --> FULL["Full HTTP headers + body\nprotocol decode/encode detail"] |
| 60 | + DEBUG --> B2C["b2c_login.py HTTP traces"] |
| 61 | +
|
| 62 | + FULL -->|"redacted via"| REDACT["_http_logging.redact_headers()"] |
| 63 | + B2C -->|"redacted via"| REDACT |
| 64 | +
|
| 65 | + REDACT --> OUTPUT["Sanitized log output"] |
| 66 | +``` |
| 67 | + |
| 68 | +### Shared HTTP Logging Module |
| 69 | + |
| 70 | +**Objective**: Centralise HTTP debug logging and credential redaction into a single module shared by `client.py` and `b2c_login.py`. |
| 71 | + |
| 72 | +A new private module `src/flameconnect/_http_logging.py` will contain: |
| 73 | + |
| 74 | +- **`redact_headers(headers: Mapping[str, str]) -> dict[str, str]`** — Returns a copy with sensitive values replaced by `"***"`. Keys matched case-insensitively: `Authorization`, `Cookie`, `Set-Cookie`, `X-CSRF-TOKEN`. For `Authorization`, the scheme prefix is preserved (e.g. `"Bearer ***"`). |
| 75 | +- **`redact_body(data: dict[str, str]) -> dict[str, str]`** — Returns a copy with the `password` key redacted. This is the form-data redaction already in `b2c_login.py`. |
| 76 | +- **`log_request(logger, method, url, *, headers=None, data=None, params=None)`** — Logs at DEBUG using `>>>` prefix. Applies `redact_headers` to headers and `redact_body` to data before logging. |
| 77 | +- **`log_response(logger, response, body=None)`** — Logs at DEBUG using `<<<` prefix. Applies `redact_headers` to response headers. Truncates body to 2000 characters. |
| 78 | + |
| 79 | +The module name `_http_logging` (not `_logging`) avoids visual confusion with the stdlib `logging` module. All functions accept a `logger` parameter rather than using a module-level logger, so each caller's messages appear under their own logger name (e.g. `flameconnect.client`, `flameconnect.b2c_login`). |
| 80 | + |
| 81 | +### Log Level Promotion |
| 82 | + |
| 83 | +**Objective**: Populate the INFO tier so `--verbose` produces meaningful output. |
| 84 | + |
| 85 | +Specific changes to existing log calls: |
| 86 | + |
| 87 | +- **`client.py:174`**: `_LOGGER.debug("%s %s -> %s", method, url, response.status)` → `_LOGGER.info(...)`. This is the request summary visible with `--verbose`. |
| 88 | +- **`auth.py:126`**: `"Attempting silent token acquisition"` → `_LOGGER.info(...)` |
| 89 | +- **`auth.py:134`**: `"Token acquired silently (refreshed from cache)"` → `_LOGGER.info(...)` |
| 90 | +- **`auth.py:138`**: `"No cached token, initiating interactive auth code flow"` → `_LOGGER.info(...)` |
| 91 | +- **`auth.py:189`**: `"Authentication successful, token acquired"` → `_LOGGER.info(...)` |
| 92 | + |
| 93 | +All other DEBUG messages (protocol decode/encode, auth internals like "Exchanging authorization code", `b2c_login.py` HTTP traces) remain at DEBUG. |
| 94 | + |
| 95 | +### Client HTTP Debug Logging |
| 96 | + |
| 97 | +**Objective**: Add full HTTP request/response debug logging to `FlameConnectClient._request`, matching the pattern already used in `b2c_login.py`. |
| 98 | + |
| 99 | +The `_request` method in `client.py` will call the shared `log_request` before the HTTP call and `log_response` after, both at DEBUG level. The existing summary line stays but is promoted to INFO (see above), so `--verbose` users see `"GET /url -> 200"` while `--debug` users additionally see headers, body, and response detail. Response bodies will be truncated to 2000 characters, consistent with the existing `b2c_login.py` behaviour. |
| 100 | + |
| 101 | +### CLI Flag Restructuring |
| 102 | + |
| 103 | +**Objective**: Add `--debug` flag and adjust `--verbose` semantics across CLI and TUI entry points. |
| 104 | + |
| 105 | +In `build_parser()`: rename `--verbose` help text to `"Enable verbose logging"` and add `--debug` with help text `"Enable verbose logging including HTTP requests and responses"`. The flags should be mutually exclusive (using `argparse.add_mutually_exclusive_group`). In `main()`, the log level selection becomes: `--debug` -> `DEBUG`, `--verbose` -> `INFO`, default -> `WARNING`. |
| 106 | + |
| 107 | +The `run_tui` function signature changes from `verbose: bool` to accept a `log_level: int` parameter (defaulting to `logging.WARNING`), and applies that level to the `flameconnect` logger. The `cmd_tui` and `async_main` callers will compute the appropriate level and pass it through. In the TUI's `DashboardScreen`, the log handler currently attaches to the `flameconnect` logger at whatever level is set — this behaviour continues unchanged, meaning DEBUG messages (including HTTP traces) will appear in the TUI messages panel when `--debug` is used. |
| 108 | + |
| 109 | +### b2c_login.py Migration |
| 110 | + |
| 111 | +**Objective**: Remove duplicated logging helpers from `b2c_login.py` and use the shared module. |
| 112 | + |
| 113 | +The `_log_request` and `_log_response` functions will be removed from `b2c_login.py` and replaced with imports from `flameconnect._http_logging`. All existing call sites will be updated to pass `_LOGGER` as the first argument. The password redaction in form data is handled by the shared `redact_body` function. |
| 114 | + |
| 115 | +## Risk Considerations and Mitigation Strategies |
| 116 | + |
| 117 | +<details> |
| 118 | +<summary>Technical Risks</summary> |
| 119 | + |
| 120 | +- **Credential leakage in logs**: Sensitive tokens or passwords could appear in log output if redaction misses a field. |
| 121 | + - **Mitigation**: Case-insensitive header matching against a known set of sensitive keys. Test coverage will verify redaction of Authorization, Cookie, password, and CSRF token values. |
| 122 | +- **JSON response bodies containing tokens**: B2C token exchange responses may contain `access_token` fields in JSON bodies. |
| 123 | + - **Mitigation**: Response body logging is only active at DEBUG level, which is opt-in for troubleshooting. The truncation to 2000 characters limits exposure. Full JSON body redaction is out of scope for this plan — users opting into `--debug` accept seeing raw (truncated) response content. |
| 124 | +</details> |
| 125 | + |
| 126 | +<details> |
| 127 | +<summary>Implementation Risks</summary> |
| 128 | + |
| 129 | +- **Breaking existing test assertions**: Tests that assert on `--verbose` behaviour or mock logging calls will need updating. There are ~20 test references to `verbose` in `test_cli_commands.py`. |
| 130 | + - **Mitigation**: Update tests alongside the implementation. Tests for `build_parser` will cover both `--verbose` and `--debug`. Tests for `async_main`/`cmd_tui` will pass `log_level` instead of `verbose`. |
| 131 | +</details> |
| 132 | + |
| 133 | +## Success Criteria |
| 134 | + |
| 135 | +### Primary Success Criteria |
| 136 | +1. `flameconnect --debug list` logs full HTTP request headers (with Bearer token redacted), request body, response status, response headers, and truncated response body |
| 137 | +2. `flameconnect --verbose list` shows INFO-level messages (request summaries, auth lifecycle) but no HTTP request/response detail |
| 138 | +3. `flameconnect list` (no flag) shows only WARNING and above |
| 139 | +4. All sensitive values (Authorization tokens, passwords, cookies, CSRF tokens) are redacted in debug output |
| 140 | +5. `mypy` strict checking passes, `ruff` passes, test coverage remains at or above 95% |
| 141 | + |
| 142 | +## Resource Requirements |
| 143 | + |
| 144 | +### Development Skills |
| 145 | +- Python async programming, `logging` module, `aiohttp` |
| 146 | +- `argparse` mutually exclusive groups |
| 147 | + |
| 148 | +### Technical Infrastructure |
| 149 | +- Existing dev toolchain: `uv`, `ruff`, `mypy`, `pytest` |
| 150 | + |
| 151 | +## Task Dependencies |
| 152 | + |
| 153 | +```mermaid |
| 154 | +graph TD |
| 155 | + 01[Task 01: Shared HTTP logging module] --> 03[Task 03: Integrate HTTP logging] |
| 156 | + 02[Task 02: CLI flags & log level promotion] --> 03 |
| 157 | +``` |
| 158 | + |
| 159 | +## Execution Blueprint |
| 160 | + |
| 161 | +**Validation Gates:** |
| 162 | +- Reference: `/config/hooks/POST_PHASE.md` |
| 163 | + |
| 164 | +### ✅ Phase 1: Foundation |
| 165 | +**Parallel Tasks:** |
| 166 | +- ✔️ Task 01: Create shared HTTP logging module (`_http_logging.py`) |
| 167 | +- ✔️ Task 02: CLI flag restructuring and log level promotion |
| 168 | + |
| 169 | +### ✅ Phase 2: Integration |
| 170 | +**Parallel Tasks:** |
| 171 | +- ✔️ Task 03: Integrate shared HTTP logging into client and b2c_login (depends on: 01, 02) |
| 172 | + |
| 173 | +### Execution Summary |
| 174 | +- Total Phases: 2 |
| 175 | +- Total Tasks: 3 |
| 176 | +- Maximum Parallelism: 2 tasks (in Phase 1) |
| 177 | +- Critical Path Length: 2 phases |
| 178 | + |
| 179 | +## Execution Summary |
| 180 | + |
| 181 | +**Status**: Completed Successfully |
| 182 | +**Completed Date**: 2026-03-11 |
| 183 | + |
| 184 | +### Results |
| 185 | +All three tasks completed across two phases. The implementation delivers: |
| 186 | +- `src/flameconnect/_http_logging.py` — shared module with `redact_headers`, `redact_body`, `log_request`, `log_response` |
| 187 | +- `--verbose` (INFO) and `--debug` (DEBUG) mutually exclusive CLI flags with correct log level mapping |
| 188 | +- Full HTTP request/response tracing in `client.py._request` at DEBUG level with credential redaction |
| 189 | +- `b2c_login.py` migrated to shared helpers (local copies removed) |
| 190 | +- 5 auth/client messages promoted from DEBUG to INFO for `--verbose` visibility |
| 191 | +- `run_tui()` signature updated from `verbose: bool` to `log_level: int` |
| 192 | +- 23 new tests in `test_http_logging.py`; all 1230 tests pass |
| 193 | + |
| 194 | +### Noteworthy Events |
| 195 | +- One pre-existing test (`TestRequestDebugLog.test_request_debug_log_format` in `test_client.py`) failed after promoting the request summary to INFO — updated to check INFO level instead of DEBUG. |
| 196 | +- `_http_logging.py` `data` parameter type was widened from `Mapping[str, str]` to `Mapping[str, Any]` to accept `client.py`'s JSON body payloads. |
| 197 | +- `client.py._request` was refactored to read `response.text()` first and then `json.loads()` instead of `response.json()`, enabling the response body to be logged before parsing. |
| 198 | + |
| 199 | +### Recommendations |
| 200 | +No follow-up actions required. |
| 201 | + |
| 202 | +## Notes |
| 203 | + |
| 204 | +### Change Log |
| 205 | +- 2026-03-11: Initial plan created |
| 206 | +- 2026-03-11: Refinement — added Log Level Promotion section to address zero INFO-level messages; renamed module from `_logging.py` to `_http_logging.py` to avoid stdlib shadowing; specified function signatures for shared module; added JSON body token risk; clarified that `log_request`/`log_response` accept a logger parameter for proper logger namespacing |
0 commit comments