feat(mxc): warn when the ETW consumer receives zero provider events - #3499
pkhodade-NV wants to merge 4 commits into
Conversation
EnableTraceEx2 succeeding only proves the request to enable the Sandboxing provider succeeded, not that the provider exists on this host/build or will ever fire. A provider-identity mismatch or a non-firing provider left the ETW->OCSF audit trail silently empty across real, successful sandbox lifecycles, with no error, warning, or diagnostic anywhere. Track raw provider-matched events received per session and add a zero-events watchdog on the consumer thread: once real sandbox activity has happened (register_launch called at least once) and a grace period elapses with zero events matched, log a warning and emit a Detection Finding [2004] naming the gap. Gated on actual activity (not just session uptime) so an idle gateway with etw_audit=true and no sandboxes created never warns. Also exposes EtwSession::events_received() alongside the existing is_capture_alive(), so a status/diagnostics surface can query capture health directly, not just infer it from tracing output. The watchdog's decision logic is extracted into a pure function (should_warn_zero_events) so it's unit-testable without a real ETW session or elevation. Signed-off-by: Prashant Khodade <pkhodade@nvidia.com> (cherry picked from commit 4fcfa716a808eaa91c6476e9c69366f91702b1fa)
…ommit warn_zero_events_received() referenced a nonexistent SESSION_NAME constant (only SESSION_NAME_PREFIX exists), so the crate failed to compile. Separately, the consumer thread's decode-or-log match on Option<DecodedEtwEvent> tripped clippy::single_match_else under -D warnings. Neither issue is specific to a platform or toolchain version -- both reproduce on a clean checkout of this branch's tip. Signed-off-by: Prashant Khodade <pkhodade@nvidia.com>
…ot PID The Sandboxing provider's events are logged under two PIDs that are never the driver's own wxc-exec PID: a short-lived launcher PID (wxc-exec.exe exits within seconds even while the sandboxed workload keeps running) and a shared, constant PID hosted by a system-wide OS broker service across unrelated sandboxes. Anchoring attribution on `register_launch`'s wxc_pid therefore left every event unattributable, so the OCSF audit trail stayed empty despite the provider firing correctly (confirmed against a raw logman/tracerpt capture running alongside this consumer). wxc-exec never reports its OS-generated `identity`/`__TlgCV__` back to the driver, so there is nothing to pre-seed `by_identity` with at registration time the way `by_pid` is pre-seeded. Track launches still awaiting their first identity/CV in a `pending_launches` queue instead, and bind opportunistically in `resolve()`: when an event carries a never-seen identity/CV and has no `by_pid` registration at all (the real-world shape of these events) and exactly one launch is pending, it can only be that launch's burst. Zero or multiple pending launches stay ambiguous and fall through to the existing unresolved-event buffer/TTL path rather than guess -- misattributing an audit event to the wrong sandbox_id is worse than dropping it. A PID registration that does exist (even generation-mismatched) is treated as positive evidence of an existing PID-reuse race and takes precedence over the opportunistic path, preserving the existing generation-key guarantees. Signed-off-by: Prashant Khodade <pkhodade@nvidia.com>
An event that ages out of the unresolved-event buffer unattributed is a permanent audit-trail gap: the OS action it represents will never appear in the OCSF log, and nothing retries it afterward. That was only visible at --log-level debug, so an operator running with the default level would never see it. Promote it to warn, matching the severity already used for the zero-events watchdog's own gap warning. Signed-off-by: Prashant Khodade <pkhodade@nvidia.com>
shailendra-nv
left a comment
shailendra-nv
left a comment
There was a problem hiding this comment.
Requesting changes for audit integrity and operability.
The singleton pending-launch fallback can attribute unrelated system-wide Sandboxing-provider activity to an OpenShell sandbox, and the new per-record warnings can flood operator logs. The current README also states that records without generation-backed evidence remain unattributed, which no longer matches this implementation.
Verification evidence at commit 92d856f0e6e1104eb72eb04444d4fd6dfdc59b29:
- PASS:
mise run --skip-tools windows:check:arm64(native ARM64 Windows workspace check; exit 0) - PASS:
cargo fmt --all -- --check - PASS:
git diff --check - Reviewed the complete current PR diff and the surrounding ETW attribution, buffering, tests, and MXC documentation.
- Not run: a live MXC/ETW runtime scenario; the static behavior below is directly exercised by the added singleton-attribution unit test.
Please keep attribution fail-closed until there is authoritative sandbox-generation correlation, rate-limit or aggregate unattributed-event warnings, and update the MXC observability documentation for the final behavior (including the new mxc-etw-zero-events finding).
| if self.pending_launches.len() != 1 { | ||
| return None; | ||
| } | ||
| self.pending_launches.pop_front().map(|(sid, _)| sid) |
There was a problem hiding this comment.
Before this branch, records without generation-backed evidence remained unattributed. Here, any fresh identity/CV from an unregistered or system-broker PID is assigned to the sole pending OpenShell launch. The surrounding comment correctly notes that unrelated non-OpenShell AppContainer or UAC activity shares this system-wide provider, so an event in the five-second window can cross-link an unrelated identity and emit subsequent events under the wrong sandbox_id. That corrupts the audit trail. Please keep this fail-closed until there is authoritative correlation, such as the driver-owned process or relay reporting the identity/CV; queue cardinality is not attribution evidence.
| for p in drained { | ||
| if now.duration_since(p.at) > PENDING_TTL { | ||
| tracing::debug!(target: "mxc_etw", pid = p.ev.process_id, "dropping unattributed (aged out) {}", p.ev.summary()); | ||
| tracing::warn!(target: "mxc_etw", pid = p.ev.process_id, "dropping unattributed (aged out) {}", p.ev.summary()); |
There was a problem hiding this comment.
This changes expected system-wide unattributed activity from debug-only to one default warning per dropped record, with no aggregation or rate limit. Bursts of unrelated AppContainer or UAC events can therefore flood operator logs indefinitely and repeat event summaries. Please aggregate or rate-limit these coverage-gap warnings and report counts, similar to OverloadReporter, rather than warning for every record.
2 participants
Summary
EnableTraceEx2/StartTraceWboth reported success, the consumer thread ran correctly, but zero OS-sourced events were ever decoded across two full, successful sandbox lifecycles -- with no error, warning, or diagnostic anywhere pointing at why.EnableTraceEx2success only proves the request to enable the provider succeeded, not that the provider exists on this host/build or will ever actually fire. A provider-identity mismatch (or a non-firing provider) left the audit trail silently empty. This PR is specifically about detection and surfacing, not diagnosing the underlying GUID/provider question, which is an environment/OS-build question outside what static code changes can resolve.Related Issue
No linked issue -- this is a localized observability fix (a missing diagnostic for an existing, real failure mode) to the MXC ETW consumer.
Changes
etw_consumer.rs:CaptureHealthgains anevents_matched: AtomicU64counter, incremented on the consumer thread for every raw event that made it through the callback's provider-GUID filter, regardless of whether TDH decode later succeeds. Exposed via a newEtwSession::events_received()accessor, alongside the existingis_capture_alive().AttributionIndexgains atotal_launchescounter (never decremented byforget), so the watchdog can tell "real sandbox activity has happened" apart from "the index is currently non-empty" (whichforgetclears on every normal sandbox completion).total_launches() > 0and a generous grace period (30s) elapses withevents_matchedstill at zero, log atracing::warn!with an actionable message and emit a Detection Finding [2004] (severity: High,is_alert: true) into the OCSF stream itself, so the gap is visible in the audit log the same way the driver's own internal events already are.etw_audit=truethat simply hasn't created any sandboxes yet never warns -- only "activity happened, nothing arrived" does.should_warn_zero_events) is extracted into a small pure function, so it's directly unit-testable without a real ETW session or elevation.Testing
total_launches_survives_forget,zero_events_watchdog_stays_quiet_without_sandbox_activity,zero_events_watchdog_stays_quiet_once_any_event_matched,zero_events_watchdog_waits_out_the_grace_period,zero_events_watchdog_fires_once_grace_elapses.cargo test -p openshell-driver-mxc --target x86_64-pc-windows-msvc --lib.Checklist
Originally opened as GitLab MR !117 against our internal mirror; re-opened here against
windowsfor upstream review. Rebased ontowindows's independently-evolvedetw_consumer.rs(queue-overload reporting, PID-reuse rewrite, and byte-tracking additions that landed there since this MR was authored) -- both sets of changes are preserved side by side.