Files
mars-nwe/doc/LOG_LEVEL_AUDIT.md
2026-06-13 05:54:54 +02:00

205 lines
9.5 KiB
Markdown

# MARS log-level audit
This audit records the legacy debug-level scheme before the namespace work starts.
It is based on the current source tree and the developer comments in
`opt/nw.ini.cmake`, `opt/nw.ini.hook.cmake`, `include/tools.h`, `include/debmask.h`
and `src/tools.c`.
## Current mechanics
Legacy logging is driven by `nw_debug` and `XDPRINTF((level, mode, ...))`.
`xdprintf()` prints a message when `nw_debug >= level`; therefore the configured
number is a threshold, not a named severity. The shipped configuration comments
for entries `100` through `106` say:
- `0` means no debug messages;
- `1` means errors and notes are reported;
- `99` means maximum debug levels.
The module-specific INI entries are:
| INI entry | Module constant | Process / area | Default in `opt/nw.ini.cmake` and hook file |
| --- | --- | --- | --- |
| `100` | local IPX helper | IPX kernel setup/debug | `0` |
| `101` | `NWSERV` | main server / watchdog / SAP startup | `1` |
| `102` | `NCPSERV` | NCP service helper | `1` |
| `103` | `NWCONN` | connection and file/namespace NCP path | `1` |
| `104` | `NWCLIENT` | startup client helper | `0`, comment says keep it zero |
| `105` | `NWBIND` | bindery/queue/server-management helper | `1` |
| `106` | `NWROUTED` | routing helper | `1` |
`get_debug_level()` also accepts an optional second token for `debug_mask`.
That mask gates `MDEBUG(mask, ...)` blocks from `include/debmask.h`:
| Mask | Meaning in source |
| --- | --- |
| `D_FH_OPEN` / `0x0001` | file open/close |
| `D_FH_LOCK` / `0x0002` | file lock/unlock |
| `D_FH_FLUSH` / `0x0004` | file flushes |
| `D_FN_NAMES` / `0x0008` | filename/name conversion |
| `D_FN_SEARCH` / `0x0010` | file search |
| `D_ACCESS` / `0x0020` | access rights |
| `D_TRUSTEES` / `0x0040` | trustees |
| `D_BIND_REQ` / `0x8000` | bindery request tracing; currently only appears in disabled code |
`xdprintf()` mode bits are independent from the level threshold:
| Mode bit | Meaning |
| --- | --- |
| `0x01` | no beginning-of-line prefix |
| `0x02` | no trailing newline; used for multi-part lines |
| `0x10` | append saved `errno` text |
## Observed level use
The active tree contains these `XDPRINTF` / direct `xdprintf` levels:
| Level | Count | Observed meaning |
| --- | ---: | --- |
| `0` | 17 | Always-on when a module has any debug enabled; packet hex fragments, unknown-NCP notes and very early diagnostics. |
| `1` | 182 | Default operational notes, warnings, login/bindery/volume/file events; matches the INI comment for “errors and notes”. |
| `2` | 219 | Common protocol/backend tracing; many `nwconn`, `nwdbm`, namespace and volume details. |
| `3` | 103 | Focused tracing, especially directory-handle mapping, semaphores and queue/share internals. |
| `4` | 18 | Moderate failure/handle/path diagnostics; often useful when debugging path resolution without full verbosity. |
| `5` | 144 | Verbose file, namespace, search and metadata path tracing. |
| `6` | 10 | Extra-deep traces; includes sensitive examples such as password-change strings and burst/direct-response details. |
| `7` | 4 | Rare deep namespace/search handle traces. |
| `8` | 2 | Rare burst/search traces. |
| `10` | 14 | Micro-level name matching, opendir and loop internals. |
| `20` | 1 | One NCPSERV loop trace. |
| `99` | 10 | Ad-hoc maximum/debug-only traces, mostly DOS alias/inode mapping plus some polling/raw-data/password traces. |
The main source distribution is:
| File | Count | Levels seen |
| --- | ---: | --- |
| `src/nwconn.c` | 196 | `0`, `1`, `2`, `3`, `5`, `6`, `8`, `99` |
| `src/nwdbm.c` | 74 | `0`, `1`, `2`, `3`, `5` |
| `src/namspace.c` | 73 | `1`, `2`, `3`, `4`, `5`, `7`, `8`, `10`, `99` |
| `src/connect.c` | 72 | `1`, `2`, `3`, `4`, `5`, `6`, `7`, `10`, `99` |
| `src/nwbind.c` | 58 | `1`, `2`, `3`, `5`, `6`, `10`, `99` |
| `src/nwserv.c` | 45 | `0`, `1`, `2`, `3`, `99` |
| `src/nwvolume.c` | 25 | `1`, `2`, `3`, `5`, `99` |
| `src/nwclient.c` | 23 | `1` |
| `src/ncpserv.c` | 18 | `1`, `2`, `5`, `6`, `10`, `20` |
| `src/nwroute.c` | 16 | `1`, `2`, `3`, `4`, `10` |
## Interpretation
The original scheme did not consistently enforce semantic severities from `0` to
`99`. It mostly follows a threshold convention, and the old developer did keep
the practical center of gravity in the low levels: the active `XDPRINTF`/direct
`xdprintf` calls are overwhelmingly in `1..5` (about nine tenths of observed call
sites). The higher values are real, but they are exceptions for deep tracing,
raw dumps, loop internals, alias/inode diagnostics and a few sensitive historical
messages, not a separate well-defined `6..99` severity ladder.
- `1` is the intended default production debug level for errors and notes.
- `2` and `3` are common troubleshooting detail.
- `4` and `5` are still normal debugging, but much more verbose.
- `6` and above are not suitable for routine logs. They can contain raw packet,
name-search, password, alias/inode or tight-loop details.
- `6..99` should be treated as one unsafe maintainer-detail class for new
facade work, not as a semantic severity ladder.
- `99` means “print only at maximum debug” and is not a stable severity.
There are outliers. Some level `0` messages are effectively “if any debug is on”
rather than true emergency severity. Some level `1` messages are ordinary
trace/noise, and some higher-level messages can expose sensitive fields. That
means a future log cleanup should not blindly translate legacy numbers to modern
severity names without reviewing each call site.
## Recommended MARS policy going forward
New code should use only levels `1` through `5` unless temporarily auditing a
specific legacy path:
| New level | Use for new code |
| --- | --- |
| `1` | errors, warnings and important operational notes that match the current default configs |
| `2` | normal protocol/backend decisions useful for endpoint bring-up |
| `3` | focused troubleshooting such as handle maps, path resolution and dispatch state |
| `4` | verbose diagnostics for a single subsystem |
| `5` | very verbose tracing that is still safe to leave compiled in |
Do not add new raw level `0`, `6`, `7`, `8`, `10`, `20` or `99` messages.
For new code, unsafe deep diagnostics must use `nwlog_detail()`, which is a
maintainer-build-only facade call and has no INI switch. In normal builds
`nwlog_detail()` must compile to a no-op or return `0`; only builds compiled
with `MAINTAINER_BUILD` may emit it.
When old call sites are touched for namespace work, prefer these conversions:
- keep useful operational messages at `1`;
- map ordinary path/search traces to `3` or `4`;
- map very verbose but safe loops to `5`;
- convert legacy `6..99` sensitive/raw/deep traces to `nwlog_detail()`;
- remove obsolete noisy traces instead of preserving them at a lower number;
- use a debug mask for noisy categories that developers may want independently
of the numeric threshold.
The long-term `nwlog`/zlog bridge should preserve this compatibility initially:
- INI entries `100` through `106` remain accepted as legacy thresholds;
- the optional mask token remains accepted for `MDEBUG` categories;
- zlog severities should be a presentation layer, not a silent semantic rewrite
of old `XDPRINTF` call sites;
- new libnwfs/namespace code should use a small wrapper that can later map
`1..5` to presentation severities without spreading `XDPRINTF` further;
- the wrapper should treat legacy numbers as verbosity thresholds first and only
then map them to backend severities/categories.
A practical first mapping for the future facade is:
| Legacy threshold | Facade interpretation | Backend presentation hint |
| --- | --- | --- |
| `1` | operational errors, warnings and important notes | error/warn/info depending on wrapper call |
| `2` | normal protocol/backend troubleshooting | debug |
| `3` | focused handle/path/dispatch troubleshooting | debug |
| `4` | verbose subsystem diagnostics | trace/debug |
| `5` | very verbose but intentionally safe tracing | trace |
| `0` | legacy if-debug-enabled special case | review before mapping |
| `6..99` | unsafe maintainer detail | `nwlog_detail()` only; emitted only in `MAINTAINER_BUILD` |
This means the facade should not simply rename `XDPRINTF(1, ...)` to `INFO` and
`XDPRINTF(5, ...)` to `TRACE` everywhere. It should provide semantic wrappers
for new code, keep the old threshold behaviour available during migration, and
review sensitive call sites before they are converted.
## Maintainer-detail rule for legacy high levels
The future facade should intentionally collapse legacy high debug values into one
explicitly unsafe API:
```c
nwlog_detail(...)
```
`nwlog_detail()` is the migration target for old `XDPRINTF`/`xdprintf` call sites
using levels `6` through `99` when the message is still useful. The individual
legacy values such as `6`, `7`, `8`, `10`, `20` and `99` were ad-hoc thresholds;
they should not survive as separate public facade levels.
The call is allowed to log sensitive or raw maintainer diagnostics, including
cleartext password-change paths, authentication material, decoded request bodies,
raw packet payloads, internal buffers, inode/alias maps and tight-loop state.
Because of that, it must not be controlled by an INI option. A production build
must not be able to enable it accidentally:
```c
int nwlog_detail(const char *fmt, ...)
{
#ifdef MAINTAINER_BUILD
/* emit as maintainer-detail, conceptually legacy level 6 */
#else
return 0;
#endif
}
```
Normal logging policy remains `1..5`. `nwlog_detail()` is not a sixth
administrator verbosity level; it is a compile-time maintainer diagnostic escape
hatch for old high-level traces that should otherwise disappear from normal
builds.