Files
personaEngine2/docs/Logging.md
T
dave cdc6bb33d3 Implement Stage A: rule engine, validation, audit, and safety gates
Completes 109 of 121 tasks. Every remaining task needs a tenant connection
(T055, T056, T101-T103) or an Azure Automation account (T115-T121).

  354 offline Pester tests      PASS
  Engine purity (Principle IV)  PASS
  Sanitization (SC-013)         PASS  (156 files)
  Graph module loaded in tests  none  (SC-008 holds)

What landed
  - Four-layer configuration validation with stable finding codes, covering
    every VR-002 and VR-003 condition, plus a 23-fixture invalid-config corpus
  - Run loop, audit records (NDJSON through a single sink), summaries,
    reconciliation, and exit codes 0-6
  - Persistence behind a single write-body builder whose result always has
    exactly one key
  - Invoke-PersonaEngine.ps1 and Edit-PersonaEngineConfig.ps1
  - Six docs, two pipelines, traceability matrix, V-5a and sanitization records

Three deviations from tasks.md, each recorded in its status block

  T033 is not in Resolve-UserPersona. evaluationErrorThreshold is run-level
  state and the rule engine is pure; a counter there would break Principle IV.
  It lives in New-PersonaRunCounter and is applied in the run loop.

  A new src/Engine/ layer holds Invoke-PersonaEngineRun. The entry script
  imports the manifest, which requires Microsoft.Graph.Authentication, so a
  loop living only inside it could not run on a machine without the Graph SDK
  and SC-004 could not be proven at all. The entry script is now a thin
  wrapper and what ships is what is tested.

  The invalid-config corpus is generated by a committed script, with the
  generated fixtures committed too, so a reviewer sees the fixture in the diff.

Defects found by running the code, not by reading it

  Group and role ID lists were double-wrapped: @(Get-PersonaGroupIdPage ...)
  around a comma-returned array collapsed every membership list into one
  bogus space-joined entry. That is a silent false non-match, exactly what
  FR-013 exists to prevent.

  A 403 whose status appears only in the exception message parsed as $null,
  which the retry policy treats as a transport error - five requests per
  account against a tenant already refusing. Status extraction now falls back
  to the message text, bounded to 400-599.

  The sanitization scan walked tracked files only, so it covered 34 of 156
  files and none of this phase's code. It now scans untracked non-ignored
  files too, and a negative control confirms it catches a planted leak.

  Test-Json reports one error per violating location, not first-failure-only
  as the V-5a draft claimed. Record and pin corrected.

Enforcement remains blocked on the V-4 security sign-off.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2026-08-20 21:48:19 -04:00

137 lines
6.4 KiB
Markdown

# Logging
Structured audit output: what is emitted, where it goes, and what may never appear in it.
The serialized contract is [audit-record.md](../specs/001-persona-engine/contracts/audit-record.md).
This document covers the operational side.
## Format and transport
Newline-delimited JSON (OTD-006). One record per line, UTF-8 without BOM, appended.
Every record passes through a single sink, `Write-PersonaAuditRecord`. Adding a transport — an
approved logging platform, an event hub, a different file layout — is a change to that one function.
If call sites wrote their own output, each new transport would mean auditing every call site again,
and the one that got missed would be silent.
| `logging.destination` | Behaviour |
| --- | --- |
| `file` | Appends NDJSON to `logging.path` |
| `stream` | Emits the record object on the PowerShell **Information** stream |
| `both` | Both |
| `none` | Nothing |
`stream` uses the Information stream rather than the success stream deliberately. Audit records on
the success stream would be indistinguishable from a function's return value — the run loop returns
its outcome there — and mixing the two turns one object into an array of several thousand. Capture
them with `-InformationVariable`, or redirect with `6>`.
### Sink failure never ends a run
A full disk or a locked file is an operational problem with the sink, not a reason to abandon a
classification run mid-population and leave the directory half-reconciled. The failure surfaces as a
warning, **once** per run, and processing continues.
Once, not once per user: a run over five thousand accounts with a locked log file should warn once,
or the warning that matters is buried in the noise it generates.
## Record types
| Type | When | Carries |
| --- | --- | --- |
| `RunStart` | Once, after mode is determined | Config path, target attribute, rule counts, whether tracing is on |
| `UserEvent` | Once per processed account | The full decision |
| `Summary` | Every `summaryInterval` accounts, and once at the end | Counters, per-rule match counts, reconciliation result |
| `RunComplete` | Once, in a `finally` block | Final counters, timing, exit code |
| `EngineDefect` | Reconciliation failure, or threshold breach | What went wrong and by how much |
`RunComplete` is written even on a fatal error. A run that died at account 400 of 5,000 leaves a
record saying exactly that — which is what lets an operator tell "the engine stopped early" from "the
engine never started", two very different incidents that produce identical evidence if the record is
written only on success.
## The common envelope
Every record, every type:
`timestamp` · `recordType` · `runId` · `engineVersion` · `configVersion` · `configurationHash` · `mode`
These appear **first** in each record, so a truncated line still identifies the run that produced it.
`runId` comes from `-CorrelationId` or is generated, and is constant for the run (NFR-005).
`configurationHash` is the SHA-256 of the configuration file bytes — two files differing only in
whitespace are different configurations for audit purposes, and the hash must be reproducible from
the artifact on disk.
## `UserEvent`
100% carry `runId`, `userPrincipalName`, and `accountObjectId` (SC-006). 100% of `Matched` records
carry `matchedRuleId`. `evaluationErrorReason` is non-null exactly when `outcome` is
`EvaluationError`.
`previousValue` is present **only** on `Updated` records, captured at write time. On any other action
there is nothing that was replaced, and a populated `previousValue` would imply otherwise to a
rollback tool reading these records later. Without it, OTD-010 rollback is impossible retroactively —
no future run can reconstruct what a value used to be.
## What may never appear
Access tokens, `Authorization` headers, client secrets, certificates, credentials, and full Graph
responses.
The guarantee is structural rather than filtered. `New-PersonaAuditRecord` accepts only named, typed
values from the decision result and the counters — there is no pass-through of an arbitrary object,
so there is nothing for a secret to ride in on.
[`AuditRedaction.Tests.ps1`](../tests/Unit/AuditRedaction.Tests.ps1) asserts this holds even when a
caller attaches a token to the decision result, and scans every serialized record for JWT and Bearer
shapes.
## Approved for logs
User principal name, account object ID, matched rule ID, stored and calculated persona values, run
ID, configuration version and hash, per-rule match counts, timing.
Runtime records naturally contain real UPNs and Object IDs. **No such value may ever be committed to
this repository** (SC-013) — the sanitization scan enforces that on every build.
## Condition tracing
`conditionTrace` is added to a `UserEvent` only when **both** gates are open: the decision result was
built with tracing, and the record was asked to include it. It carries the per-rule result
(`True` / `False` / `Unknown`) and priority.
Tracing widens what the log contains beyond the approved set, so it requires
`logging.acknowledgeConditionTracing` in the same configuration (`PE-SAF-006`). Tracing never changes
a decision — if it could, a debug run would stop being evidence about the real one, and
[`ConditionTrace.Tests.ps1`](../tests/Unit/ConditionTrace.Tests.ps1) asserts the outcome is identical
with and without it.
## Querying
```powershell
# Everything from one run
Get-Content <LOG-OUTPUT-PATH> | ForEach-Object { $_ | ConvertFrom-Json } |
Where-Object runId -eq '<RUN-ID>'
# Accounts a run changed, with what it replaced
Get-Content <LOG-OUTPUT-PATH> | ForEach-Object { $_ | ConvertFrom-Json } |
Where-Object { $_.recordType -eq 'UserEvent' -and $_.action -eq 'Updated' } |
Select-Object userPrincipalName, previousValue, calculatedPersona, matchedRuleId
# Accounts that could not be evaluated, and why
Get-Content <LOG-OUTPUT-PATH> | ForEach-Object { $_ | ConvertFrom-Json } |
Where-Object outcome -eq 'EvaluationError' |
Select-Object userPrincipalName, evaluationErrorReason
# Which rule set produced a given decision
Get-Content <LOG-OUTPUT-PATH> | ForEach-Object { $_ | ConvertFrom-Json } |
Where-Object recordType -eq 'RunStart' |
Select-Object runId, configVersion, configurationHash, mode
```
## Retention
Not set by this engine. Records contain UPNs and Object IDs, so retention is governed by the
organization's identity-data policy rather than by anything in this repository. Decide it before the
first enforcing run, not after.