← Back to PRs

#22475: fix(logging): correct levelToMinLevel mapping to match tslog numbering

by ronaldslc open 2026-02-21 06:37 View on GitHub →
size: S
# fix(logging): correct `levelToMinLevel` mapping to match tslog numbering ## Summary - **Problem:** `levelToMinLevel()` in `src/logging/levels.ts` mapped log levels in reverse order compared to tslog's actual `minLevel` numbering. Setting `logging.level: "debug"` in config produced `minLevel: 4`, which tslog interprets as **WARN** — silently dropping all DEBUG and INFO entries from the root logger's file transport. - **Why it matters:** `logVerbose()` (used by media understanding decisions, plugin command routing, attachment security checks, and many other subsystems) writes via the root logger's `.debug()` method. These entries never reached the log file regardless of configuration, making production debugging of verbose-gated code paths completely impossible. - **What changed:** Corrected the `levelToMinLevel` mapping to match [tslog's documented level numbering](https://tslog.js.org/#/?id=default-log-level): `0: silly, 1: trace, 2: debug, 3: info, 4: warn, 5: error, 6: fatal`. Added 8 regression tests covering mapping values, ordering invariants, and tslog filtering semantics. - **What did NOT change (scope boundary):** Subsystem loggers are unaffected — they create child loggers via `getChildLogger()` with `minLevel: undefined` (tslog defaults to allow-all), so they never relied on the broken mapping. The `isFileLogLevelEnabled()` guard also remains correct since it compares two values from the same mapping (relative ordering preserved). Default `logging.level: "info"` maps to `3` in both old and new mappings — no behavior change for default configs. ### The Bug (before → after) The old mapping was the exact reverse of tslog's numbering: | Level | Old (broken) | tslog actual | New (fixed) | |----------|-------------|--------------|-------------| | `trace` | 5 | 1 | 1 | | `debug` | 4 | 2 | 2 | | `info` | 3 | 3 | 3 | | `warn` | 2 | 4 | 4 | | `error` | 1 | 5 | 5 | | `fatal` | 0 | 6 | 6 | | `silent` | ∞ | — | ∞ | > **Reference:** tslog documents its default log levels as `0: silly, 1: trace, 2: debug, 3: info, 4: warn, 5: error, 6: fatal` > — [tslog.js.org → Default log level](https://tslog.js.org/#/?id=default-log-level) > > tslog's `minLevel` setting filters out all log entries whose `logLevelId` is **below** the configured `minLevel`. > — [tslog.js.org → minLevel](https://tslog.js.org/#/?id=minlevel) ## Change Type (select all) - [x] Bug fix - [ ] Feature - [ ] Refactor - [ ] Docs - [ ] Security hardening - [ ] Chore/infra ## Scope (select all touched areas) - [x] Gateway / orchestration - [ ] Skills / tool execution - [ ] Auth / tokens - [ ] Memory / storage - [ ] Integrations - [ ] API / contracts - [ ] UI / DX - [ ] CI/CD / infra ## Linked Issue/PR - Closes # - Related # ## User-visible / Behavior Changes - When `logging.level` is set to `"debug"` or `"trace"`, `logVerbose()` entries (media understanding decisions, plugin command routing, attachment security checks, etc.) now correctly appear in the rolling log file (`/tmp/openclaw/openclaw-YYYY-MM-DD.log`). - Previously these entries were silently dropped despite `shouldLogVerbose()` returning `true`. - No change to default behavior (`logging.level: "info"` — the default — maps to `minLevel: 3` in both old and new mappings). ## Security Impact (required) - New permissions/capabilities? `No` - Secrets/tokens handling changed? `No` - New/changed network calls? `No` - Command/tool execution surface changed? `No` - Data access scope changed? `No` ## Repro + Verification ### Environment - OS: Linux (Docker) - Runtime/container: Node 22.22.0 in `openclaw:local` Docker image - Model/provider: openrouterx (GLM 5 primary, Qwen 3.5 imageModel) - Integration/channel: Telegram - Relevant config: `"logging": { "level": "debug" }` ### Steps 1. Set `logging.level: "debug"` in `~/.openclaw/openclaw.json` 2. Send a photo via Telegram to trigger media understanding 3. Check log file: `grep "verbose" /tmp/openclaw/openclaw-YYYY-MM-DD.log` ### Expected - Log file contains `logVerbose()` entries including `"Media understanding ..."` decision summaries ### Actual (before fix) - Zero `verbose` entries in log file despite 174 total log lines and `logging.level: "debug"` configured ## Evidence - [x] Failing test/log before + passing after - [x] Trace/log snippets **tslog level verification (before fix):** ```bash # OpenClaw mapped "debug" → minLevel:4, which tslog treats as WARN $ node -e " const {Logger} = require('tslog'); const l = new Logger({type:'hidden', minLevel:4}); let count = 0; l.attachTransport(o => { count++; console.log('TRANSPORT:', o._meta.logLevelId, o._meta.logLevelName); }); l.debug('debug msg'); l.info('info msg'); l.warn('warn msg'); l.error('error msg'); console.log('Total entries reaching transport:', count); " TRANSPORT: 4 WARN TRANSPORT: 5 ERROR Total entries reaching transport: 2 # ⬆ debug (2) and info (3) were silently dropped because minLevel=4 (WARN) ``` **Log file evidence (before fix):** ```bash # tslog actual numbering vs OpenClaw's broken mapping: # tslog: SILLY=0, TRACE=1, DEBUG=2, INFO=3, WARN=4, ERROR=5, FATAL=6 # OpenClaw (broken): fatal=0, error=1, warn=2, info=3, debug=4, trace=5 # ↑ info=3 matched by coincidence, but debug/trace/warn/error/fatal were all wrong $ grep -o '"logLevelId":[0-9]*,"logLevelName":"[A-Z]*"' log | sort | uniq -c | sort -rn 93 "logLevelId":2,"logLevelName":"DEBUG" # subsystem child loggers (unaffected, minLevel=undefined) 72 "logLevelId":3,"logLevelName":"INFO" 7 "logLevelId":5,"logLevelName":"ERROR" 3 "logLevelId":4,"logLevelName":"WARN" 0 entries from logVerbose() (root logger .debug()) # ← THE BUG ``` **Tests (after fix):** ``` ✓ src/logging/levels.test.ts (8 tests) 2ms ✓ maps levels to match tslog minLevel numbering (trace=1 .. fatal=6) ✓ debug < info < warn (more verbose levels have lower minLevel values) ✓ setting minLevel=debug allows debug calls through (tslog semantics) ✓ setting minLevel=info filters out debug calls (tslog semantics) ✓ normalizeLogLevel returns valid levels as-is ✓ normalizeLogLevel falls back for unknown levels ✓ normalizeLogLevel falls back when undefined ✓ normalizeLogLevel trims whitespace ``` ## Human Verification (required) - **Verified scenarios:** Confirmed tslog's actual level IDs via live `node -e` in the gateway container. Confirmed zero `verbose` entries exist in the production log file with `logging.level: "debug"`. Verified subsystem DEBUG entries (93 of them) were unaffected because child loggers use `minLevel: undefined`. Confirmed the bundled code in `entry.js` shares a single `loggingState` singleton across all chunks. - **Edge cases checked:** `isFileLogLevelEnabled()` uses the same mapping for both sides of its comparison — relative ordering is preserved so no behavior change. `"info"` maps to `3` in both old and new mappings (default config unaffected). `"silent"` maps to `Infinity` in both. - **What I did not verify:** End-to-end log output with the fix deployed (requires rebuild + restart of the Docker gateway). ## Compatibility / Migration - Backward compatible? `Yes` - Config/env changes? `No` - Migration needed? `No` ## Failure Recovery (if this breaks) - How to disable/revert this change quickly: Revert `src/logging/levels.ts` to previous mapping, rebuild - Files/config to restore: `src/logging/levels.ts` - Known bad symptoms reviewers should watch for: Log file growing significantly larger at `logging.level: "debug"` (expected — verbose entries that were silently dropped will now appear) ## Risks and Mitigations - **Risk:** Log file size may increase when `logging.level: "debug"` is set, since `logVerbose()` entries will now actually be written. - **Mitigation:** This is the intended behavior per the docs. Log files already roll daily and are pruned after 24h. Default `logging.level: "info"` is unaffected (maps to `3` in both old and new mappings). <!-- greptile_comment --> <h3>Greptile Summary</h3> Correctly maps log levels to match tslog's numbering (trace=1, debug=2, info=3, warn=4, error=5, fatal=6), fixing the root logger's `minLevel` configuration. Previously, `logging.level: "debug"` mapped to `minLevel: 4` which tslog interpreted as WARN, silently dropping all debug entries from the file transport. **Critical issue found**: The mapping fix is correct, but breaks two comparison functions that relied on the old inverted ordering: - `src/logging/logger.ts:110` - `isFileLogLevelEnabled()` uses `<=` which worked with the old reversed mapping (debug=4 > info=3), but fails with the new correct mapping (debug=2 < info=3). Must change to `>=`. - `src/logging/subsystem.ts:33` - `shouldLogToConsole()` has the same bug and will incorrectly display debug messages to console when `consoleLevel="info"`. The PR description claims "relative ordering preserved" so the comparisons remain correct, but this is incorrect - the **direction** of ordering flipped (from descending to ascending), so comparison operators must also flip. <h3>Confidence Score: 1/5</h3> - This PR contains critical logical errors that will break log level filtering for both console and file output - While the tslog mapping correction is valid and well-tested, the PR introduces breaking bugs in two comparison functions that determine whether messages should be logged. These functions use `<=` which worked with the old inverted mapping but fails with the new ascending mapping - they must use `>=` instead. This will cause debug/trace messages to appear in console and trigger unnecessary logger...

Most Similar PRs