Files
safetynet/docs/development-observability.md
T

224 lines
15 KiB
Markdown
Raw Normal View History

# Development observability
Run `npm run debug:collector` and verify `http://127.0.0.1:4318/health`.
Start the management service with `OTEL_EXPORTER_OTLP_ENDPOINT=http://127.0.0.1:4318`.
Enable browser diagnostics through a normally published signed policy: `enabled: true`,
`mode: debug`, endpoint above, and debug sampling of 1 for controlled reproduction.
Administrators can disable diagnostics centrally; mandatory review still applies.
Reproduce the feature, inspect `/api/summary` for slow stages and inspect
`/api/trace/<traceId>` for parent/child timings. Browser management requests carry
W3C trace context into backend HTTP spans. AI inspection, provider requests,
response reading/decoding and library organization have separate backend stages.
Use the native tabs smoke fixture to verify real Electron exports and correlation.
The receiver listens only on numeric loopback, rejects foreign origins and hosts,
and stores encrypted batches under ignored `data/observability`. AES-256-GCM keys
are protected by Windows DPAPI. The summary contains bounded timing metadata;
it is a local developer tool accessible to the same machine's users, not a
production SIEM or an authenticated remote service. Recent trace lookup is held
in memory and resets on restart. Each encrypted segment has a 50 MiB development
limit. The collector retains an active segment and at most two generated retired
segments, plus a separately pinned previous archive. Inspect `activeBytes`,
`legacyBytes`, `retiredBytes` and `rejectedWrites`; investigate collection failures
instead of assuming exports succeeded. See [retention](development-collector-retention.md).
Ordinary traces never contain passwords, tokens, prompt bodies or document text.
Security audit and restricted encrypted forensic evidence are separate pipelines.
Debug mode now exports eight internal inspector stages: inspect, parse, OCR, OCR model initialization, YARA, macro extraction, semantic inference and semantic model initialization. The worker sends bounded in-memory timing records through its existing private pipe; it gains no network capability. Browser/backend import creates child spans with original timestamps under the active request trace. Invalid/off/stale metadata is discarded without changing the verdict. These named stages do not trace every function or native-model kernel. Add named stages when investigating further gaps, without weakening DLP or retrying protected actions.
The repository's AGENTS.md requires this workflow for subsequent development.
## Coverage verification, 2026-10-13
The live collector reported 3,147 spans, 2,482 log records and 36 metric records,
with zero rejected storage writes. Twenty focused diagnostics, OTLP export,
inspector timing, collector validation/retention and failure-path tests passed.
These counts are a process snapshot, not a completeness claim.
Agent RPC instrumentation now wraps each request in `agent.request`; decrypt,
authorization, audit, dispatch, projection and encryption run beneath that parent.
The browser diagnostic operation allowlist accepts the new name. A real protected
RPC test verifies asynchronous parent/child nesting without recording arguments
or response content. The combined transport/diagnostics suite passes 38 tests;
A subsequent actual Electron run verifies exported parent/child phases linked to an attributable durable agent event; Windows packaged verification remains a separate gate.
The actual native agent audit proof links `browser.agent` to
`browser.management` and `server.request` under trace
`f8e35fd442e718995d9274c646fb8e08`. The native upload helper-failure proof links a
recording `browser.upload.fault` span, its lease parent, two logs and the durable
audit event under trace `e6d26d4edf738a7b4f6f562ab2112f5b`. Older traces may be in
the protected pinned archive rather than the current in-memory index.
A sampled slow `browser.parser` scan lasted 1,049 ms but contained only the outer
span in the live index. Do not infer which parser or model stage caused that
duration from an outer span alone: reproduce with signed debug mode enabled and
verify the expected inspector children before attributing a performance issue.
The current individual native proof links principal `reader-a` to
trace `3a0c31cbf53d7808e39a91daf2aaa3d7`. Its request took 81.019 ms,
the two durable audit phases totaled 77.598 ms and adapter dispatch took
0.313 ms. This single local run points to audit persistence as the dominant
stage; it is not a throughput benchmark. Preserve pre-execution durable audit
when investigating latency. Do not optimize by removing an audit gate or retrying
an action. The proof is in `artifacts/individual-agent-native-proof.json`.
The final Windows package verifier checks current source and runs both shipped
legacy and individual DPAPI/PQ clients successfully.
## Latest interaction and session measurements
The actual protected interaction proof uses trace
`32cbbb58088d193301c5f6ac530284af`: 30 spans, verified parent correlation,
capture 0.3353 ms, challenge 8.1735 ms, encryption 0.4718 ms, send 62.1817 ms
and acknowledgement 0.4234 ms. The backend store stage took 54.2629 ms.
Collector rejected writes were zero. These are one local reproduction's
measurements, not performance guarantees.
After session-title classification was added, the actual native session inventory
proof uses trace `64013e27cfc37bc3792983bc06149c87`: request 85.675 ms,
session adapter 1.0637 ms and durable audit phases 33.3975 and 47.2472 ms.
This fixture did not enable the semantic model; it cannot establish semantic-model
latency. The native proof confirms a confidential title is masked while preserving
its opaque session ID.
A parallel fixture timed out before enrollment and therefore before signed
diagnostics activation. Its isolated rerun and restart reached the shell in
794/806 ms. Safe local startup snapshots were added; the original timeout's cause
is unresolved. Do not describe that failure as a traced DLP/model regression.
The current Windows package proof and 515-test suite passed before the subsequent
export-counter refinement. Ignored proof artifacts remain local.
After the refinement and policy child stages, the final suite passes 522 tests.
Real signed policy/bookmark fixtures verify actual OTLP child spans and disabled
transitions. Windows build, packaged-runtime verification and the native tabs
proof pass. The native receiver attributes exports by actual `service.name`:
browser exports stay at 18 across revocation while backend collection remains
independent. The earlier aggregate assertion conflated the two services; its
failed run is retained rather than presented as successful. Do not retroactively
assign the original extra batch to a service without its original payload.
Foreground gesture development used actual traces to find a second attribution
gap: a queue flusher started by one event delivered the next event under the first
async context. `withCorrelation` now validates each durable record's own IDs and
`audit.deliver` creates a recording delivery child under that source parent.
Malformed IDs clear unrelated context, and current signed sampling/disable still
applies. Real OTLP regression tests and three actual human-event traces prove
distinct parents and complete evidence phase correlation. Trace
`b7783f42197d0cff83957b0ee96e8296` has 17 spans, capture 19.50 ms and send 13.20 ms;
`62e09413b9a42f4a58bd7f99485176ac` and
`545ddac025113e50effed4e9a2ac87ee` each also have 17 spans. Collector rejected writes
were zero. These are local reproduction timings, not throughput guarantees.
On 2026-10-13, the running protected collector and the actual exported trace
`fd47bcfc8b259712101ad3c81c1d95c1` were inspected again. The request took
724.3133 ms, its first audit phase 682.6577 ms, and dispatch 2.0827 ms.
Its correlated audit delivery took 52.7383 ms. The audit phase alone does not
establish whether serialization, DPAPI, filesystem synchronization or scheduling
caused the delay. New synchronous persistence spans separate `audit.serialize`,
`audit.encrypt`, `audit.write`, `audit.fsync` and `audit.commit`, without changing
the synchronous persistence boundary or retrying a write. Only fixed operation
identifiers and timings enter diagnostic attributes; no audit payload or paths.
Previously collected traces cannot supply these newly added stages.
The subsequent actual Electron vault fixture passed with the added stages.
Trace `e98cac3e18c6bd7b0e0442f033a7fa2d` exports all five persistence
children under `agent.audit`: serialization 0.0544 ms, encryption 0.0501 ms,
write 7.2461 ms, fsync 2.3703 ms and close/rename 14.7423 ms. These timings
describe this new run; they do not resolve the previous 683 ms observation.
The five-stage parentage was checked against the live collector for both list
and fill requests, with zero rejected writes. Twelve existing diagnostics tests
and four dedicated real OTLP tests pass, including central disable, secret
redaction, synchronous return/throw preservation and no replay on instrumentation
failure. At that stage, session adapter exports were proven in a fixture;
native browser restoration required the subsequent integration proof below.
The actual two-process Windows session proof now exports save/list/restore stages
and their audit persistence children. A delayed HTTPS receiver also verifies
that manually switching away and back aborts restoration, preserves existing tabs
and never requests the second saved destination. Trace
`583a1d4dbc80fb2cbcb135b1622a4993` records the failed native stage at 1410.0137 ms
and owned-tab rollback at 0.7242 ms. The delay was intentional fixture behavior;
it is not a production performance result. Collector rejected writes were zero.
On 2026-10-13, the protected live receiver was queried for controlled-login trace
`aedaae84014f4d5e14c6d7b441d7e0f7`. Eight credential phases were verified to
have the same native request ancestor: claim, parse, match, residual, headers,
header-values, authorization and completion. The body gate took 216.4937 ms;
local inspection took 178.5054 ms, while its inspector span took 12.283203 ms
and YARA 11.866699 ms. Enterprise inspection took 4.8818 ms. The remaining
local-inspection interval cannot be attributed to parsing or YARA from these
spans alone; investigate IPC, scheduling and containment before claiming a cause.
The receiver reported zero rejected writes and uses Windows DPAPI plus AES-GCM
for local archive storage. These are actual local fixture measurements, not
production latency guarantees. Credential values and form descriptors are
excluded from debug attributes; security evidence uses its separate policy and
audit pipeline. Trace exports remain centrally disableable.
The follow-up review found credential substring HMAC checks outside the named
matching stage. They now use `credential.match`, including checks of additional
fields and unexpected destinations. A real OTLP receiver regression verifies
six internal stage parents, timestamps, secret exclusion and central disable.
The combined broker, OTLP, policy-transition and request/header deadline suite
passes 29 tests. The earlier native trace predates this final matching refinement;
its timings must not be presented as measurements of the refined code.
The subsequent real native split-header test failed although the broker suite was
green. A separate Electron 44.7 / Chromium 152 header-order probe established the
cause: `X-Credential-One` and `X-Credential-Two` arrived with `sec-ch-ua-mobile`
between them. Joining every header value did not reconstruct the synthetic
credential; joining the two fragments did. Evidence retains only header names,
indices and booleans (`artifacts/credential-header-order-proof.json`), never values.
This native fact motivates bounded two-fragment checks independent of header
iteration order. It does not prove coverage of arbitrary fragmentation/encoding.
After the bounded pair fix, the fresh actual Windows native run passes both
unregistered-credential escape cases. Trace
`6709b228cb8ce71a88acc7584a27c5a1` contains 101 spans; credential header checking
took 15.6353 ms (header-values child 14.4573 ms), authorization 0.9952 ms and
terminal audit completion 24.8035 ms. Actual request ancestry and original plus
alternate synthetic secret exclusion were verified. ICAP observed no credentials
in 54 scans; collector rejected writes remained zero. The full suite passes
668 tests. The failing predecessor remains separate evidence and is not counted
as a pass. These timings are local fixture observations, not general benchmarks.
The receiver-strengthened final native run also passes: exactly four approved
credential POSTs, zero public POSTs, zero replays and zero credential URL/header
leaks at the independent HTTPS receiver. It privately checks any two header
fragments rather than relying on all-values concatenation. Current trace
`050f7f44bc009f949c838f8a067649e4` has 101 spans with verified request ancestry;
collector rejected writes remain zero. Evidence: `artifacts/controlled-login-native-proof.json`
and `artifacts/controlled-login-receiver-proof-native.log`. Earlier native failures
and the prior successful proof remain distinct local evidence.
The screenshot increment used actual traces to separate capture, structural PNG
validation, OCR, enterprise inspection, audit, projection and final release.
The first native run (`2a2507264480c9ed8fdb585a5608d292`) spent 6953.918 ms in
local inspection, with OCR 6469.757 ms, capture 358.558 ms and AV 5.039 ms.
These local cold-run observations identify OCR as the largest measured child;
they do not prove the cause of all remaining IPC/containment overhead.
Independent review found unobserved open-shadow mutations and a late policy/tab
release gap after the helper returned. Shadow roots now have private observers
and pending-record draining; final encrypted reply requires a private actor-bound
policy/native-frame release guard checked synchronously beside reply. Latest
native trace `aad45c8a85f25619a233b78e132d7bad` verifies eight stages. The final
`visual.release` takes 0.2507 ms under the outer agent request; the seven helper
stages retain the inner screenshot action ancestry. Real tests reclassify the
page while retaining the screenshot grants, switch the foreground after helper
return and mutate/revert open-shadow content; all suppress image delivery.
The native fixture also proves real contained OCR of a confidential canvas,
mandatory ICAP PNG blocking and secret exclusion from ordinary ECS/OTLP output.
Five PNG AV scans include one expected block; collector rejected writes are zero.
Real OTLP regression tests prove responsible-stage ERROR status, redaction and
central disable. No pixels, encoded images, raw DOM attributes or extracted OCR
text are diagnostic attributes. The local receiver is protected and bounded,
not a production forensic archive. The admin fixture's earlier 429 failure came
from short synthetic cookies sharing the IP bucket; realistic-length synthetic
capabilities resolved it without changing production limits. Its subsequent
200 completed API requests all have correlated traces.