Skip to content

Commit 13d9e81

Browse files
committed
WIP(logging): second rescue -- doc reconciliation and PHI inventories (BACKLOG #122)
*** STILL A RESCUE COMMIT. STILL UNVERIFIED. DO NOT MERGE. *** The lane kept working after the first rescue commit and was cut off again by the session limit. Eight more files were uncommitted, including further work on logging_guard.py and test_log_write_guard.py plus two PHI-inventory tests (test_phi_at_rest_inventory.py, test_phi_logging_inventory.py) and the ADR index. --no-verify again, deliberately and recorded rather than hidden: the alternative was leaving eight modified files with no SHA a second time. The .mf-measure/ scratch directory is deliberately NOT staged. WHAT A RESUMER MUST DO, because none of it was done: - re-run the canonical quartet from scratch; there is no verified state here - establish a fresh baseline in THIS worktree before the first edit and diff node-id by node-id; there is no stable baseline on this box - confirm ADR 0162's number came from scripts/coord/alloc.ps1 and was NOT chosen by grepping -- a grepped number merges clean and corrupts the ledger - the two-stage design is the whole safety story and must not be collapsed: roll to a fresh file and RECOVER first; stop the connection ONLY if the replacement also cannot be written
1 parent 9996720 commit 13d9e81

8 files changed

Lines changed: 67 additions & 7 deletions

File tree

docs/CONFIGURATION.md

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,7 @@
1616
> **An unimplemented key is accepted *silently*** — every section model is pydantic `extra="ignore"`, so
1717
> a forward-looking file still loads rather than failing. The accepted-but-ignored keys, each also
1818
> flagged where it is documented: the **whole `[engine]` section** (see [`[engine]`](#engine)),
19-
> `[delivery].outbox_workers`/`dead_letter`, `[logging].file`/`max_bytes`/`backups`,
19+
> `[delivery].outbox_workers`/`dead_letter`,
2020
> `[retention].audit_days` (**reserved/keep-forever by design**), `[reference].max_staleness_seconds`,
2121
> `[ai].baa_attested`, and `[update_check].index_url`/`index_allowed_hosts`.
2222
@@ -651,7 +651,7 @@ Only `baa_attested` is still a forward-compat placeholder (accepted-but-ignored)
651651
|---|---|---|---|
652652
| `level` | enum | `info` | log level. `debug` can surface full message bodies / raw field values into the general log. **`serve` refuses `debug` on a `production_instance` only** (Gate #1, keyed on the production tier alone — see `[security].production_instance`). It is **not** keyed on PHI: since [ADR 0148](adr/0148-phi-default-posture-and-an-explicit-security-enforcement-level.md) a `dev`/`staging` instance also carries PHI, and one of those **will start at `debug` with nothing refusing**. Don't raise any PHI box to `debug` — the gate will not stop you. |
653653
| `format` | enum | `text` | stdout rendering: `text` (default) or structured `json` (one object per line). Stdlib only — no structlog |
654-
| `log_dir` | str | _unset_ | the directory NSSM (or another supervisor) **rotates the engine's captured stdout/stderr into**. The engine never writes log **files** itself (it logs to stdout); set this only to tell it where the supervisor parks them, and `GET /status` then **meters that directory's total bytes + filesystem free space** alongside the DB metrics (#50). Unset = stdout-only, no metering. **Metadata only** — the file contents are never read. |
654+
| `log_dir` | str | _unset_ | the directory NSSM (or another supervisor) **rotates the engine's captured stdout/stderr into**. The engine writes no log **file** of its own unless `file` below is set (opt-in, off by default); set this only to tell it where the supervisor parks the captured stdout, and `GET /status` then **meters that directory's total bytes + filesystem free space** alongside the DB metrics (#50). Unset = stdout-only, no metering. **Metadata only** — the file contents are never read. |
655655
| `forward_enabled` | bool | _derived_ | ship a copy of every record off-box to a syslog/SIEM collector (sec-offbox-log) so evidence survives a host compromise. **Default-on-when-configured (ADR 0080):** unset ⇒ on iff `forward_host` is set. Set `false` to opt out even with a host; no `forward_host` ⇒ off (stdout-only, unchanged) |
656656
| `forward_host` | str || syslog/SIEM collector host. Setting it turns forwarding on by default (above) |
657657
| `forward_port` | int | `514` | collector port (1–65535) |
@@ -666,7 +666,10 @@ Only `baa_attested` is still a forward-compat placeholder (accepted-but-ignored)
666666
| `ntp_peer` | str || NTP/SNTP host to compare the local clock against (**required** when `require_time_sync`) |
667667
| `time_sync_max_skew_seconds` | float | `2.0` | \|local − peer\| above this is "skewed" (must be > 0) |
668668
| `time_sync_fail_closed` | bool | `false` | **refuse to start** (instead of warn) on skew or an unreachable peer. Further opt-in; requires `require_time_sync` |
669-
| `file`, `max_bytes`, `backups` | str/int || **accepted-but-ignored** (planned) rotation — none is a `LoggingSettings` field. The engine logs to stdout and NSSM rotates it; `log_dir` above is how you point the engine at where it lands |
669+
| `file` | str | _unset_ | **opt-in application-log file the ENGINE owns end to end** (#122, [ADR 0162](adr/0162-fail-closed-application-log-write-guard-detect-roll-and-stop.md)) — it opens it, size-rotates it, and rolls it aside on a write failure. Distinct from `log_dir` above, which is where the **supervisor** parks the captured stdout: **one file, one rotation owner**, so a `file` inside `log_dir` is **refused at load** rather than left to fight NSSM. Unset (the default) = stdout-only, unchanged. A path the engine cannot open **refuses startup** — an engine that starts unable to log is the blindness this closes |
670+
| `file_max_bytes` | int | `50000000` | size-rotate `file` at ~50 MB (`0` = never rotate on size). Engine-side rotation, unrelated to NSSM's. The legacy planned spelling `max_bytes` is **refused at load** naming this key, rather than silently ignored |
671+
| `file_backup_count` | int | `5` | how many `file.1``file.N` backups to keep (the legacy planned spelling `backups` is likewise refused, naming this key). The `*.broken-*` files a write failure rolls aside are **deliberately outside** this chain — they are incident evidence, and a rotation that could delete them would delete the record of the failure |
672+
| `on_write_failure` | enum | `stop` | **fail-closed control (#122):** when a log sink cannot be written **and** the fresh sink rolled into its place cannot be written either, stop every connection this engine **process** owns — inbounds stop accepting, outbounds pause with their queued rows **retained** (never dead-lettered). A first failure alone never stops anything; the roll absorbs the transient. Scope is the process because the application log is process-global and no per-connection attribution exists ([ADR 0162](adr/0162-fail-closed-application-log-write-guard-detect-roll-and-stop.md) §4); under engine sharding that is the shard's connections. `continue` is the documented opt-out — it still rolls and still alerts, it just keeps processing with no log. The stop is announced by a `log_write_failed` alert through the notifier, a `connection_stopped` per halted connection naming the cause, and `GET /status`'s `log_sinks` block |
670673

671674
> PHI redaction + control-char scrubbing are **always-on handler filters** (not a toggle) applied to
672675
> **every** sink, including the off-box forwarder ([`logging_setup.py`](../messagefoundry/logging_setup.py),

docs/SERVICE.md

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -390,6 +390,42 @@ icacls "C:\ProgramData\MessageFoundry\logs" /inheritance:r `
390390
/grant "Administrators:(OI)(CI)F" "NT SERVICE\MessageFoundry:(OI)(CI)M"
391391
```
392392

393+
### Who owns which log file, and what happens when one cannot be written
394+
395+
Two things can write log files here, and **each file has exactly one owner** — two rotators renaming
396+
one file is how a log gets shredded, and the loser of that race is the log you read after an incident.
397+
398+
| File | Owner | Rotation | Configured by |
399+
|---|---|---|---|
400+
| The captured stdout/stderr (`logs\service-*.log` above) | **NSSM** | NSSM, at ~10 MB | the install script; `[logging].log_dir` only *tells the engine where they are*, for `GET /status` metering (#50), log retention (#120) and the console's log viewer |
401+
| `[logging].file` (optional, off by default) | **the engine** | the engine, at `[logging].file_max_bytes`, keeping `file_backup_count` backups | `[logging]` in your settings TOML |
402+
403+
`[logging].file` is **opt-in and unset by default**; leave it unset and the engine is stdout-only
404+
exactly as before. If you do set it, **put it outside `[logging].log_dir`** and do not point NSSM at
405+
it — the engine refuses to start otherwise, naming the collision.
406+
407+
**The engine stops processing when it cannot log** (BACKLOG #122,
408+
[ADR 0162](adr/0162-fail-closed-application-log-write-guard-detect-roll-and-stop.md)), in two stages:
409+
410+
1. **Roll.** A write failure renames the broken file aside as `<name>.broken-<UTC>-<n>`, opens a fresh
411+
file at the live path, records the rollover event in it and re-writes the record that failed. A
412+
momentary lock or an antivirus scan heals here and **stops nothing**.
413+
2. **Stop.** If the **replacement** cannot be written either, every connection this engine process
414+
owns is stopped: inbounds stop accepting, outbounds pause with their queued messages **retained**
415+
(not dead-lettered). You are told three ways — a `log_write_failed` alert through the notifier
416+
(email/webhook, which does not go through the log that broke), a `connection_stopped` alert per
417+
halted connection naming the log as the cause, and `GET /status`'s `log_sinks` block, which is read
418+
from memory and still answers when the disk does not.
419+
420+
Recover by fixing the disk or permissions and then reloading or restarting the service; the retained
421+
queue drains. Set `[logging].on_write_failure = "continue"` if you would rather the engine keep
422+
running with no log — it still rolls and still alerts, it just does not stop. The `*.broken-*` files
423+
are incident evidence and are deliberately left for you to review and remove; nothing rotates them
424+
away.
425+
426+
**The message store is unaffected by any of this.** It is a separate durable record: a message already
427+
accepted and committed was ACKed, and a log-write failure neither loses it nor re-delivers it.
428+
393429
## Admin console (in a browser)
394430

395431
This service is **headless**. Operators watch and run it from the **browser web console** served

0 commit comments

Comments
 (0)