diff --git a/.gitattributes b/.gitattributes index 7c78e6099..b3ba74198 100644 --- a/.gitattributes +++ b/.gitattributes @@ -16,6 +16,7 @@ *.scss text eol=lf *.html text eol=lf *.slog text eol=lf +*.mc text eol=lf devolutions-gateway/openapi/doc/index.adoc linguist-generated merge=binary devolutions-gateway/openapi/dotnet-client/src/** linguist-generated merge=binary diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 70a94a8d9..d3cb5836f 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -354,8 +354,6 @@ jobs: $VSINSTALLDIR = $(vswhere.exe -latest -requires Microsoft.VisualStudio.Component.VC.Llvm.Clang -property installationPath) Write-Output "LIBCLANG_PATH=$VSINSTALLDIR\VC\Tools\Llvm\x64\bin" | Out-File -FilePath $env:GITHUB_PATH -Encoding utf8 -Append - # Install Visual Studio Developer PowerShell Module for cmdlets such as Enter-VsDevShell - Install-Module VsDevShell -Force shell: pwsh - name: Configure Windows (arm) runner @@ -735,9 +733,6 @@ jobs: # NASM is required by aws-lc-rs (used as rustls crypto backend) choco install nasm - # Install Visual Studio Developer PowerShell Module for cmdlets such as Enter-VsDevShell - Install-Module VsDevShell -Force - # We need to add the NASM binary folder to the PATH manually. Write-Output "$Env:ProgramFiles\NASM" | Out-File -FilePath $env:GITHUB_PATH -Encoding utf8 -Append shell: pwsh @@ -746,9 +741,31 @@ jobs: id: find_mc if: ${{ matrix.os == 'windows' }} run: | - Enter-VsDevShell - $path = (Get-Command -Type Application mc).Source | Split-Path -Parent + $sdkRoots = @( + $Env:WindowsSdkDir + (Get-ItemPropertyValue -Path "HKLM:\SOFTWARE\Microsoft\Windows Kits\Installed Roots" -Name KitsRoot10 -ErrorAction SilentlyContinue) + "${Env:ProgramFiles(x86)}\Windows Kits\10" + ) | Where-Object { $_ } | Select-Object -Unique + $candidates = @() + if ($Env:WindowsSdkVerBinPath) { + $candidates += Join-Path $Env:WindowsSdkVerBinPath "mc.exe" + $candidates += Join-Path $Env:WindowsSdkVerBinPath "x64\mc.exe" + } + foreach ($root in $sdkRoots) { + $bin = Join-Path $root "bin" + $candidates += Join-Path $bin "x64\mc.exe" + $candidates += Get-ChildItem -LiteralPath $bin -Directory -ErrorAction SilentlyContinue | + Where-Object Name -Match '^\d+\.\d+\.\d+\.\d+$' | + Sort-Object { [version]$_.Name } -Descending | + ForEach-Object { Join-Path $_.FullName "x64\mc.exe" } + } + $mc = $candidates | Where-Object { Test-Path -LiteralPath $_ -PathType Leaf } | Select-Object -First 1 + if (-Not $mc) { + throw "mc.exe was not found in the installed Windows SDK" + } + $path = Split-Path -Parent $mc Write-Output "windows_sdk_ver_bin_path=$path" | Out-File -FilePath $env:GITHUB_OUTPUT -Append -Encoding utf8 + Write-Output $path | Out-File -FilePath $env:GITHUB_PATH -Append -Encoding utf8 shell: pwsh - name: Build @@ -1014,6 +1031,37 @@ jobs: if: ${{ matrix.os == 'windows' }} uses: microsoft/setup-msbuild@v3 + - name: Find mc.exe + id: find_mc + if: ${{ matrix.os == 'windows' }} + run: | + $sdkRoots = @( + $Env:WindowsSdkDir + (Get-ItemPropertyValue -Path "HKLM:\SOFTWARE\Microsoft\Windows Kits\Installed Roots" -Name KitsRoot10 -ErrorAction SilentlyContinue) + "${Env:ProgramFiles(x86)}\Windows Kits\10" + ) | Where-Object { $_ } | Select-Object -Unique + $candidates = @() + if ($Env:WindowsSdkVerBinPath) { + $candidates += Join-Path $Env:WindowsSdkVerBinPath "mc.exe" + $candidates += Join-Path $Env:WindowsSdkVerBinPath "x64\mc.exe" + } + foreach ($root in $sdkRoots) { + $bin = Join-Path $root "bin" + $candidates += Join-Path $bin "x64\mc.exe" + $candidates += Get-ChildItem -LiteralPath $bin -Directory -ErrorAction SilentlyContinue | + Where-Object Name -Match '^\d+\.\d+\.\d+\.\d+$' | + Sort-Object { [version]$_.Name } -Descending | + ForEach-Object { Join-Path $_.FullName "x64\mc.exe" } + } + $mc = $candidates | Where-Object { Test-Path -LiteralPath $_ -PathType Leaf } | Select-Object -First 1 + if (-Not $mc) { + throw "mc.exe was not found in the installed Windows SDK" + } + $path = Split-Path -Parent $mc + Write-Output "windows_sdk_ver_bin_path=$path" | Out-File -FilePath $env:GITHUB_OUTPUT -Append -Encoding utf8 + Write-Output $path | Out-File -FilePath $env:GITHUB_PATH -Append -Encoding utf8 + shell: pwsh + - name: Build run: | if ($Env:RUNNER_OS -eq "Windows") { @@ -1024,6 +1072,7 @@ jobs: $Env:DAGENT_TUN2SOCKS_EXE = "${{ steps.tun2socks.outputs.tun2socks-executable-path }}" $Env:DAGENT_WINTUN_DLL = "${{ steps.tun2socks.outputs.wintun-library-path }}" $Env:DAGENT_MULTI_PWSH_EXECUTABLE = "${{ steps.multi-pwsh.outputs.executable-path }}" + $Env:WindowsSdkVerBinPath = '${{ steps.find_mc.outputs.windows_sdk_ver_bin_path }}' } if ($Env:RUNNER_OS -eq "Linux") { @@ -1161,6 +1210,20 @@ jobs: run: dotnet test utils/dotnet/GatewayUtils.sln shell: pwsh + agent-installer-event-log-tests: + name: Agent installer Event Log lifecycle tests + runs-on: windows-2022 + needs: [preflight] + + steps: + - name: Checkout ${{ github.repository }} + uses: actions/checkout@v6 + with: + ref: ${{ needs.preflight.outputs.ref }} + + - name: Tests + run: dotnet test package/AgentWindowsManaged.Tests/DevolutionsAgent.Installer.Tests.csproj + shell: pwsh winapi-sanitizer-tests: name: Windows API sanitizer tests @@ -1405,7 +1468,7 @@ jobs: success: name: Success if: ${{ always() }} - needs: [tests, agent-tunnel-e2e, agent-policy-e2e, lints, check-dependencies, jetsocat-lipo, devolutions-gateway-powershell, gateway-service-account-tests, devolutions-gateway, devolutions-gateway-merge, devolutions-pedm-desktop, devolutions-agent, devolutions-agent-merge, devolutions-pedm-client, dotnet-utils-tests, winapi-sanitizer-tests, winapi-miri, pedm-simulator, secure-memory-verifier] + needs: [tests, agent-tunnel-e2e, agent-policy-e2e, lints, check-dependencies, jetsocat-lipo, devolutions-gateway-powershell, gateway-service-account-tests, devolutions-gateway, devolutions-gateway-merge, devolutions-pedm-desktop, devolutions-agent, devolutions-agent-merge, devolutions-pedm-client, dotnet-utils-tests, agent-installer-event-log-tests, winapi-sanitizer-tests, winapi-miri, pedm-simulator, secure-memory-verifier] runs-on: ubuntu-latest steps: diff --git a/Cargo.lock b/Cargo.lock index 8136ade6a..e84bb2930 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -96,6 +96,13 @@ dependencies = [ "tokio 1.52.3", ] +[[package]] +name = "agent-sysevent-codes" +version = "0.0.0" +dependencies = [ + "sysevent", +] + [[package]] name = "agent-tunnel" version = "0.0.0" @@ -4804,6 +4811,7 @@ dependencies = [ name = "now-package-broker" version = "0.0.0" dependencies = [ + "agent-sysevent-codes", "anyhow", "async-trait", "axum 0.8.9", @@ -4826,6 +4834,8 @@ dependencies = [ "serde", "serde_json", "sha2 0.10.9", + "sysevent", + "sysevent-winevent", "tempfile", "tokio 1.52.3", "tokio-util", @@ -4854,9 +4864,9 @@ dependencies = [ [[package]] name = "now-policy-api" -version = "0.6.0" +version = "0.7.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8b61d66fd334d2dac6150d1ab83f3831ec4b0ee20272fb3386fbe5b5e31c6663" +checksum = "fcd733577077eb870204207836f596ec3fc8fe4876d3652be7f0dee4a52e0dc8" dependencies = [ "chrono", "derive_more", @@ -4871,9 +4881,9 @@ dependencies = [ [[package]] name = "now-policy-server-template" -version = "0.6.0" +version = "0.7.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "fee165964d3b2dddfa2c6283b820d5cad337277d51365cf77e6b1376668f529d" +checksum = "567491bfc7bf5615d1854cc951172987fe638084b86c6c153ad6d860f0096ae8" dependencies = [ "aide 0.15.1", "async-trait", @@ -7613,6 +7623,7 @@ dependencies = [ name = "testsuite" version = "0.0.0" dependencies = [ + "agent-sysevent-codes", "agent-tunnel", "agent-tunnel-libsql", "agent-tunnel-proto", @@ -7646,6 +7657,7 @@ dependencies = [ "serde", "serde_json", "sysevent", + "sysevent-codes", "sysevent-syslog", "sysevent-winevent", "tempfile", diff --git a/crates/agent-policy-tester/src/windows.rs b/crates/agent-policy-tester/src/windows.rs index 26ac51f30..db8d93d22 100644 --- a/crates/agent-policy-tester/src/windows.rs +++ b/crates/agent-policy-tester/src/windows.rs @@ -307,7 +307,6 @@ async fn assert_redirected_policy_rejected( "ExpectedStoreToken": management["Management"]["StoreToken"], "Operation": "Repair", "ConflictHandling": "Reject", - "WarningsAcknowledged": false, "Draft": full_policy(), "ValidationReceipt": "invalid" }); @@ -393,7 +392,6 @@ async fn replace_policy( "ExpectedStoreToken": expected_store_token, "Operation": operation, "ConflictHandling": "Reject", - "WarningsAcknowledged": true, "Draft": validation["CanonicalDraft"], "ValidationReceipt": validation["ValidationReceipt"] }); diff --git a/crates/agent-sysevent-codes/Cargo.toml b/crates/agent-sysevent-codes/Cargo.toml new file mode 100644 index 000000000..beef0008e --- /dev/null +++ b/crates/agent-sysevent-codes/Cargo.toml @@ -0,0 +1,13 @@ +[package] +name = "agent-sysevent-codes" +version = "0.0.0" +edition = "2024" +authors = ["Devolutions Inc. "] +license = "MIT OR Apache-2.0" +publish = false + +[lints] +workspace = true + +[dependencies] +sysevent.path = "../sysevent" diff --git a/crates/agent-sysevent-codes/src/lib.rs b/crates/agent-sysevent-codes/src/lib.rs new file mode 100644 index 000000000..83fc18d65 --- /dev/null +++ b/crates/agent-sysevent-codes/src/lib.rs @@ -0,0 +1,259 @@ +//! Devolutions Agent Windows Event Log event definitions. +//! +//! The Agent message catalog holds exactly the codes declared here, so the Agent never ships a +//! message it cannot emit. + +use std::path::Path; + +use sysevent::{Entry, Severity}; + +// 1000-1099 **Service/Lifecycle** + +/// Fired after the Agent service started. +pub const SERVICE_STARTED: u32 = 1000; +/// Graceful stop received. +pub const SERVICE_STOPPING: u32 = 1001; +/// Failed to init config. +pub const CONFIG_INVALID: u32 = 1010; +/// Top-level start failure (often transient). +pub const START_FAILED: u32 = 1020; +/// A boot crash trace was persisted. +pub const BOOT_STACKTRACE_WRITTEN: u32 = 1030; + +pub fn service_started(version: impl ToString) -> Entry { + Entry::new("Service started") + .event_code(SERVICE_STARTED) + .severity(Severity::Info) + .field("version", version) +} + +pub fn service_stopping(reason: impl ToString) -> Entry { + Entry::new("Service stopping") + .event_code(SERVICE_STOPPING) + .severity(Severity::Info) + .field("reason", reason) +} + +pub fn config_invalid(error: impl std::fmt::Display, path: impl AsRef) -> Entry { + Entry::new("Configuration invalid") + .event_code(CONFIG_INVALID) + .severity(Severity::Critical) + .field("path", path.as_ref().display()) + .field("error_chain", format!("{error:#}")) + .field("reason_code", "invalid_config") +} + +pub fn start_failed(error: impl std::fmt::Display, cause: impl ToString) -> Entry { + Entry::new("Start failed") + .event_code(START_FAILED) + .severity(Severity::Error) + .field("cause", cause) // e.g. "bind", "dependency", "tls", "io" + .field("error_chain", format!("{error:#}")) +} + +pub fn boot_stacktrace_written(path: &Path) -> Entry { + Entry::new("Boot stacktrace written") + .event_code(BOOT_STACKTRACE_WRITTEN) + .severity(Severity::Warning) + .field("path", path.display()) +} + +// 6000-6099 **User Sessions** + +/// `DevolutionsSession.exe` started in session; include session id & kind (console/remote). +pub const USER_SESSION_PROCESS_STARTED: u32 = 6000; +/// Exit code; who triggered. +pub const USER_SESSION_PROCESS_TERMINATED: u32 = 6001; + +pub fn user_session_process_started(session_id: u32, kind: impl ToString, exe: impl ToString) -> Entry { + Entry::new("User session process started") + .event_code(USER_SESSION_PROCESS_STARTED) + .severity(Severity::Info) + .field("session_id", session_id) + .field("kind", kind) // "console","remote" + .field("exe", exe) +} + +pub fn user_session_process_terminated(session_id: u32, exit_code: i32, by: impl ToString) -> Entry { + Entry::new("User session process terminated") + .event_code(USER_SESSION_PROCESS_TERMINATED) + .severity(Severity::Info) + .field("session_id", session_id) + .field("exit_code", exit_code) + .field("by", by) // "user","service","timeout" +} + +// 6100-6199 **Updater** + +pub const UPDATER_TASK_ENABLED: u32 = 6100; +pub const UPDATER_ERROR: u32 = 6101; + +pub fn updater_task_enabled() -> Entry { + Entry::new("Updater task enabled") + .event_code(UPDATER_TASK_ENABLED) + .severity(Severity::Info) +} + +pub fn updater_error(step: impl ToString, error: impl std::fmt::Display) -> Entry { + Entry::new("Updater error") + .event_code(UPDATER_ERROR) + .severity(Severity::Error) + .field("step", step) // "download","verify","apply","rollback" + .field("error_chain", format!("{error:#}")) +} + +// 6200-6299 **PEDM** + +pub const PEDM_ENABLED: u32 = 6200; + +pub fn pedm_enabled() -> Entry { + Entry::new("PEDM enabled") + .event_code(PEDM_ENABLED) + .severity(Severity::Info) +} + +// 8000-8099 **Package Broker / Policy Management** + +pub const POLICY_WRITE_ATTEMPTED: u32 = 8000; +pub const POLICY_WRITE_DENIED: u32 = 8001; +pub const POLICY_CREATE_FAILED: u32 = 8002; +pub const POLICY_CREATE_SUCCEEDED: u32 = 8003; +pub const POLICY_CHANGE_FAILED: u32 = 8004; +pub const POLICY_CHANGE_SUCCEEDED: u32 = 8005; +pub const POLICY_EXTERNAL_CHANGE_APPLIED: u32 = 8010; +pub const POLICY_EXTERNAL_CHANGE_REJECTED: u32 = 8011; + +pub fn policy_write_attempted( + actor_sid: impl ToString, + actor_exe: impl ToString, + intent: impl ToString, + path: &Path, +) -> Entry { + Entry::new("Policy management write attempted") + .event_code(POLICY_WRITE_ATTEMPTED) + .severity(Severity::Info) + .field("actor_sid", actor_sid) + .field("actor_exe", actor_exe) + .field("intent", intent) + .field("path", path.display()) +} + +pub fn policy_write_denied( + actor_sid: impl ToString, + actor_exe: impl ToString, + intent: impl ToString, + path: &Path, + reason: impl ToString, +) -> Entry { + Entry::new("Policy management write denied") + .event_code(POLICY_WRITE_DENIED) + .severity(Severity::Warning) + .field("actor_sid", actor_sid) + .field("actor_exe", actor_exe) + .field("intent", intent) + .field("path", path.display()) + .field("reason", reason) +} + +#[expect( + clippy::too_many_arguments, + reason = "the shared builder keeps the Create and change failure events field-compatible" +)] +pub fn policy_write_failed( + event_code: u32, + message: &'static str, + actor_sid: impl ToString, + actor_exe: impl ToString, + intent: impl ToString, + path: impl AsRef, + operation: impl ToString, + outcome: impl ToString, + reason: impl ToString, +) -> Entry { + Entry::new(message) + .event_code(event_code) + .severity(Severity::Error) + .field("actor_sid", actor_sid) + .field("actor_exe", actor_exe) + .field("intent", intent) + .field("path", path.as_ref().display()) + .field("operation", operation) + .field("outcome", outcome) + .field("reason", reason) +} + +#[expect( + clippy::too_many_arguments, + reason = "the audit event records both policy identities and the operation outcome" +)] +pub fn policy_write_succeeded( + event_code: u32, + message: &'static str, + actor_sid: impl ToString, + actor_exe: impl ToString, + path: impl AsRef, + old_id: impl ToString, + old_revision: impl ToString, + new_id: impl ToString, + new_revision: u32, + intent: impl ToString, + operation: impl ToString, + outcome: impl ToString, +) -> Entry { + Entry::new(message) + .event_code(event_code) + .severity(Severity::Info) + .field("actor_sid", actor_sid) + .field("actor_exe", actor_exe) + .field("path", path.as_ref().display()) + .field("old_id", old_id) + .field("old_revision", old_revision) + .field("new_id", new_id) + .field("new_revision", new_revision) + .field("intent", intent) + .field("operation", operation) + .field("outcome", outcome) +} + +pub fn policy_external_change_applied(path: impl AsRef, new_id: impl ToString, new_revision: u32) -> Entry { + Entry::new("External policy change applied") + .event_code(POLICY_EXTERNAL_CHANGE_APPLIED) + .severity(Severity::Notice) + .field("path", path.as_ref().display()) + .field("new_id", new_id) + .field("new_revision", new_revision) +} + +pub fn policy_external_change_rejected(path: impl AsRef, reason: impl ToString) -> Entry { + Entry::new("External policy change rejected") + .event_code(POLICY_EXTERNAL_CHANGE_REJECTED) + .severity(Severity::Warning) + .field("path", path.as_ref().display()) + .field("reason", reason) +} + +/// Every declared Agent event code, paired with its symbolic name. +/// +/// `devolutions-agent.mc` is checked against this inventory, and the check is an exact match in +/// both directions, so adding a code here means adding its messages to the catalog, and a code +/// this crate does not declare must never appear there. +pub static DECLARED_CODES: &[(&str, u32)] = &[ + ("SERVICE_STARTED", SERVICE_STARTED), + ("SERVICE_STOPPING", SERVICE_STOPPING), + ("CONFIG_INVALID", CONFIG_INVALID), + ("START_FAILED", START_FAILED), + ("BOOT_STACKTRACE_WRITTEN", BOOT_STACKTRACE_WRITTEN), + ("USER_SESSION_PROCESS_STARTED", USER_SESSION_PROCESS_STARTED), + ("USER_SESSION_PROCESS_TERMINATED", USER_SESSION_PROCESS_TERMINATED), + ("UPDATER_TASK_ENABLED", UPDATER_TASK_ENABLED), + ("UPDATER_ERROR", UPDATER_ERROR), + ("PEDM_ENABLED", PEDM_ENABLED), + ("POLICY_WRITE_ATTEMPTED", POLICY_WRITE_ATTEMPTED), + ("POLICY_WRITE_DENIED", POLICY_WRITE_DENIED), + ("POLICY_CREATE_FAILED", POLICY_CREATE_FAILED), + ("POLICY_CREATE_SUCCEEDED", POLICY_CREATE_SUCCEEDED), + ("POLICY_CHANGE_FAILED", POLICY_CHANGE_FAILED), + ("POLICY_CHANGE_SUCCEEDED", POLICY_CHANGE_SUCCEEDED), + ("POLICY_EXTERNAL_CHANGE_APPLIED", POLICY_EXTERNAL_CHANGE_APPLIED), + ("POLICY_EXTERNAL_CHANGE_REJECTED", POLICY_EXTERNAL_CHANGE_REJECTED), +]; diff --git a/crates/now-package-broker/Cargo.toml b/crates/now-package-broker/Cargo.toml index 662cbc510..337463431 100644 --- a/crates/now-package-broker/Cargo.toml +++ b/crates/now-package-broker/Cargo.toml @@ -34,14 +34,17 @@ notify = { version = "7", default-features = false } http-body-util = "0.1" mime = "0.3" now-policy = "=0.5.0" -now-policy-api = "=0.6.0" -now-policy-server-template = "=0.6.0" +now-policy-api = "0.7" +now-policy-server-template = "0.7" parking_lot = "0.12" regex = "1" semver = "1" serde = "1" serde_json = "1" sha2 = "0.10" +sysevent = { path = "../sysevent" } +agent-sysevent-codes = { path = "../agent-sysevent-codes" } +sysevent-winevent = { path = "../sysevent-winevent" } tokio = { version = "1.52", features = ["net", "io-util", "rt", "macros", "parking_lot", "fs", "sync", "time"] } tokio-util = "0.7" tower-service = "0.3" diff --git a/crates/now-package-broker/src/audit.rs b/crates/now-package-broker/src/audit.rs new file mode 100644 index 000000000..9bf89dd48 --- /dev/null +++ b/crates/now-package-broker/src/audit.rs @@ -0,0 +1,1182 @@ +//! Structured audit events for policy management writes and external policy changes. + +use std::path::{Path, PathBuf}; +use std::sync::Arc; +#[cfg(all(not(test), not(debug_assertions)))] +use std::sync::atomic::AtomicU64; +use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering}; + +use agent_sysevent_codes as policy_events; +use now_policy_api::{PolicyManagementState, PolicyReplacementOperation}; +use sysevent::Entry; +#[cfg(not(test))] +use sysevent::Severity; +#[cfg(all(not(test), not(debug_assertions)))] +use sysevent::SystemEventSink; +use win_api_wrappers::identity::sid::Sid; + +const INTENT: &str = "PUT /v1/policy"; +const MAX_SID_BYTES: usize = 256; +const MAX_PATH_BYTES: usize = 1024; +const MAX_POLICY_ID_BYTES: usize = 256; +/// Slots of the Event Log queue kept for terminal outcomes and external changes. +/// +/// Only the outcome of an authenticated policy write, which the policy store serializes, and the +/// policy store's own observation of an external change take these slots. Attempts and denials, +/// which an unauthenticated client can produce at will, are refused before reaching them. +#[cfg(any(test, not(debug_assertions)))] +const EVENT_LOG_OUTCOME_RESERVE: usize = 64; + +/// Slots of the Event Log queue that write attempts and denials may occupy. +/// +/// The write attempt is recorded before the pipe client is authenticated, so a client that never +/// authenticates can produce this class at will. It is the class that yields when the sink +/// saturates. +#[cfg(any(test, not(debug_assertions)))] +const EVENT_LOG_ADMISSION_BUDGET: usize = 256; + +/// Capacity of the queue holding every policy audit entry waiting for the Event Log worker. +#[cfg(any(test, not(debug_assertions)))] +const EVENT_LOG_QUEUE_CAPACITY: usize = EVENT_LOG_ADMISSION_BUDGET + EVENT_LOG_OUTCOME_RESERVE; + +/// How long the shutdown waits for the accepted entries to reach the Event Log sink, and for the +/// worker to stop after the queue is closed. +/// +/// The worker is a plain thread, so a sink that stopped making progress would otherwise hold the +/// shutdown until the agent stops the process. Entries still queued when this expires stay in the +/// queue, and the worker keeps emitting them for as long as the process lives. +#[cfg(any(test, not(debug_assertions)))] +const EVENT_LOG_SHUTDOWN_GRACE: std::time::Duration = std::time::Duration::from_secs(5); + +/// How often a bounded shutdown wait re-checks what it is waiting for. +#[cfg(any(test, not(debug_assertions)))] +const EVENT_LOG_POLL_INTERVAL: std::time::Duration = std::time::Duration::from_millis(10); + +static RECORDER: std::sync::OnceLock> = std::sync::OnceLock::new(); + +/// Connections that may still record a policy audit event. +static AUDIT_PRODUCERS: AtomicUsize = AtomicUsize::new(0); + +/// The process-wide recorder, started on the first policy audit event. +fn recorder() -> &'static Arc { + RECORDER.get_or_init(default_recorder) +} + +/// Held by a connection for as long as it may record a terminal policy audit event. +/// +/// Serving a connection can commit a policy and record its outcome, and that work is synchronous, +/// so the shutdown can give up on a connection that is still inside it. Holding a lease for the +/// lifetime of the connection keeps [`drain`] from closing the queue under it. +pub(crate) struct AuditLease(&'static AtomicUsize); + +impl AuditLease { + /// Marks the caller as able to record until the returned lease is dropped. + #[must_use] + pub(crate) fn acquire() -> Self { + Self::acquire_on(&AUDIT_PRODUCERS) + } + + fn acquire_on(counter: &'static AtomicUsize) -> Self { + counter.fetch_add(1, Ordering::AcqRel); + Self(counter) + } +} + +impl Drop for AuditLease { + fn drop(&mut self) { + self.0.fetch_sub(1, Ordering::AcqRel); + } +} + +/// Stops accepting policy audit events and waits for the ones already accepted to reach the sink. +/// +/// The recorder lives in a process-lifetime static, so its worker is otherwise killed with whatever +/// it is still holding when the process exits. +/// +/// A connection that can still record an event keeps the queue open: closing it would reject the +/// terminal event of a policy write that is still finishing, so the queue is flushed and left +/// accepting for as long as the process lives instead. +pub(crate) fn drain() { + if let Some(recorder) = RECORDER.get() { + shutdown(recorder.as_ref(), AUDIT_PRODUCERS.load(Ordering::Acquire)); + } +} + +/// Closes the queue, unless a connection that can still record into it is alive. +fn shutdown(recorder: &dyn AuditRecorder, producers: usize) { + if producers == 0 { + recorder.drain(); + } else { + tracing::warn!( + producers, + "Named pipe connections are still running blocking work; flushing the policy audit queue without closing it" + ); + recorder.flush(); + } +} + +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +pub(crate) enum DenialReason { + AuthenticationFailed, + AdministratorRequired, + RequestRejected, +} + +impl DenialReason { + const fn as_str(self) -> &'static str { + match self { + Self::AuthenticationFailed => "authentication_failed", + Self::AdministratorRequired => "administrator_required", + Self::RequestRejected => "request_rejected", + } + } +} + +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +pub(crate) enum FailureReason { + MonitoringUnavailable, + StaleStoreToken, + PathNotWritable, + InvalidPolicy, + InvalidReceipt, + RevisionConflict, + DraftCommitFailed, + SerializationFailed, + PersistenceFailed, + ConditionalPublicationFailed, + ActivationFailed, +} + +impl FailureReason { + const fn as_str(self) -> &'static str { + match self { + Self::MonitoringUnavailable => "monitoring_unavailable", + Self::StaleStoreToken => "stale_store_token", + Self::PathNotWritable => "path_not_writable", + Self::InvalidPolicy => "invalid_policy", + Self::InvalidReceipt => "invalid_receipt", + Self::RevisionConflict => "revision_conflict", + Self::DraftCommitFailed => "draft_commit_failed", + Self::SerializationFailed => "serialization_failed", + Self::PersistenceFailed => "persistence_failed", + Self::ConditionalPublicationFailed => "conditional_publication_failed", + Self::ActivationFailed => "activation_failed", + } + } +} + +/// Which class an audit entry belongs to. +/// +/// Both classes share one queue, so entries reach the sink in the order they were recorded. The +/// class only decides whether an entry may be refused to keep capacity for the other class. +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +enum EntryClass { + /// A write attempt or a denial. Recorded from unauthenticated requests, so it may be dropped + /// when the sink saturates. + Admission, + /// The terminal outcome of a policy write, or the observation of an external change. It does + /// not consume the admission budget, so only a full queue or a gone worker can refuse it. + Outcome, +} + +impl EntryClass { + #[cfg(all(not(test), not(debug_assertions)))] + const fn as_str(self) -> &'static str { + match self { + Self::Admission => "admission", + Self::Outcome => "outcome", + } + } +} + +/// Why the Event Log queue refused an entry. +#[cfg(any(test, not(debug_assertions)))] +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +enum QueueRefusal { + /// The queue, or the slots this class may occupy, is full. + Full, + /// The worker is gone, so nothing can reach the sink anymore. + Disconnected, +} + +#[cfg(all(not(test), not(debug_assertions)))] +impl QueueRefusal { + const fn as_str(self) -> &'static str { + match self { + Self::Full => "queue_full", + Self::Disconnected => "worker_disconnected", + } + } +} + +trait AuditRecorder: Send + Sync { + /// Records one entry of `class`. Admission is best-effort for both classes: an + /// [`EntryClass::Admission`] entry is refused once admissions fill their budget, and either + /// class is refused while the shared queue is full or its worker is gone. + fn record(&self, entry: Entry, class: EntryClass); + + /// Stops accepting entries and waits for the accepted ones to be emitted. + fn drain(&self) {} + + /// Waits for the accepted entries to be emitted, without closing the queue. + /// + /// Used instead of [`Self::drain`] while a connection that can still record is alive, so its + /// terminal event is emitted rather than rejected. + fn flush(&self) {} +} + +fn default_recorder() -> Arc { + #[cfg(test)] + { + Arc::new(tests::TestRecorder) + } + #[cfg(all(not(test), debug_assertions))] + { + Arc::new(TracingRecorder) + } + #[cfg(all(not(test), not(debug_assertions)))] + { + match SystemRecorder::new() { + Ok(recorder) => Arc::new(recorder), + Err(error) => { + tracing::error!(%error, "Failed to start the Windows Event Log policy audit worker"); + Arc::new(TracingRecorder) + } + } + } +} + +#[cfg(not(test))] +struct TracingRecorder; + +#[cfg(not(test))] +impl AuditRecorder for TracingRecorder { + fn record(&self, entry: Entry, _: EntryClass) { + trace_entry(&entry); + } +} + +#[cfg(all(not(test), not(debug_assertions)))] +struct SystemRecorder { + queue: parking_lot::Mutex, + dropped: AtomicU64, +} + +/// The queue and the worker thread that move accepted entries to the Windows Event Log. +/// +/// Every entry shares one bounded queue, so entries reach the sink in the order they were recorded +/// and an accepted write's attempt precedes its terminal outcome. Write attempts and denials are +/// refused once they occupy [`EVENT_LOG_ADMISSION_BUDGET`] slots, so a flood of unauthenticated +/// attempts cannot fill the queue and starve outcomes and external changes. +#[cfg(any(test, not(debug_assertions)))] +struct EventLogQueue { + /// `None` once [`Self::drain`] closed the queue, so no later entry can be accepted. + sender: Option>, + /// Write attempts and denials still queued, shared with the worker that dequeues them. + admission_pending: Arc, + /// Entries accepted but not yet emitted, shared with the worker that emits them. + pending: Arc, + worker: Option>, +} + +#[cfg(any(test, not(debug_assertions)))] +impl EventLogQueue { + fn start(emit: impl FnMut(Entry) + Send + 'static) -> std::io::Result { + let (sender, receiver) = std::sync::mpsc::sync_channel(EVENT_LOG_QUEUE_CAPACITY); + let admission_pending = Arc::new(AtomicUsize::new(0)); + let pending = Arc::new(AtomicUsize::new(0)); + let queued = Arc::clone(&admission_pending); + let outstanding = Arc::clone(&pending); + let worker = std::thread::Builder::new() + .name("policy-audit-event-log".to_owned()) + .spawn(move || event_log_worker(&receiver, &queued, &outstanding, emit))?; + + Ok(Self { + sender: Some(sender), + admission_pending, + pending, + worker: Some(worker), + }) + } + + /// Queues one entry, unless its class is over budget or the queue is full or closed. + fn record(&mut self, entry: Entry, class: EntryClass) -> Result<(), QueueRefusal> { + // The queue is closed after the broker drained it, so nothing can be emitted anymore. + let Some(sender) = self.sender.as_ref() else { + return Err(QueueRefusal::Disconnected); + }; + if class == EntryClass::Admission { + // Claim the slot before sending, so concurrent attempts cannot overdraw the budget. + if self.admission_pending.fetch_add(1, Ordering::Relaxed) >= EVENT_LOG_ADMISSION_BUDGET { + self.admission_pending.fetch_sub(1, Ordering::Relaxed); + return Err(QueueRefusal::Full); + } + } + // Claim the entry before sending, so the worker cannot emit it before a flush counts it. + self.pending.fetch_add(1, Ordering::AcqRel); + match sender.try_send((entry, class)) { + Ok(()) => Ok(()), + Err(error) => { + self.pending.fetch_sub(1, Ordering::AcqRel); + if class == EntryClass::Admission { + // The entry never entered the queue, so its claimed slot is free again. + self.admission_pending.fetch_sub(1, Ordering::Relaxed); + } + Err(match error { + std::sync::mpsc::TrySendError::Full(_) => QueueRefusal::Full, + std::sync::mpsc::TrySendError::Disconnected(_) => QueueRefusal::Disconnected, + }) + } + } + } + + fn drain(&mut self) { + self.drain_with_grace(EVENT_LOG_SHUTDOWN_GRACE); + } + + /// Closes the queue and waits, at most for `grace`, for the worker to emit what is left. + /// + /// Dropping the sender ends the worker's iteration as soon as the queue is empty, so waiting for + /// it is normally bounded by the sink. A sink that stopped making progress would hold the + /// shutdown until the agent stops the process instead, so the worker is detached once the grace + /// expires: it owns nothing the process needs to release. + fn drain_with_grace(&mut self, grace: std::time::Duration) { + // Dropping the sender ends the worker's iteration as soon as the queue is empty. + self.sender = None; + let Some(worker) = self.worker.take() else { + return; + }; + if !wait_until(|| worker.is_finished(), grace) { + tracing::warn!( + "The Windows Event Log policy audit worker is still emitting after the queue was closed; the agent is stopping without waiting for it" + ); + return; + } + if worker.join().is_err() { + tracing::warn!("The Windows Event Log policy audit worker panicked"); + } + } +} + +#[cfg(all(not(test), not(debug_assertions)))] +impl SystemRecorder { + fn new() -> std::io::Result { + Ok(Self { + queue: parking_lot::Mutex::new(EventLogQueue::start(event_log_emitter())?), + dropped: AtomicU64::new(0), + }) + } +} + +#[cfg(all(not(test), not(debug_assertions)))] +impl AuditRecorder for SystemRecorder { + fn record(&self, entry: Entry, class: EntryClass) { + trace_entry(&entry); + if let Some(refusal) = self.queue.lock().record(entry, class).err() { + let dropped = self.dropped.fetch_add(1, Ordering::Relaxed) + 1; + if dropped.is_power_of_two() { + tracing::warn!( + dropped, + class = class.as_str(), + error = refusal.as_str(), + "Dropped policy audit Windows Event Log entries" + ); + } + } + } + + fn drain(&self) { + // The lock keeps a concurrent `record` from queueing an entry the closed queue would drop. + self.queue.lock().drain(); + } + + fn flush(&self) { + // The pending count is read outside the lock, so a connection that is finishing its policy + // write can still record its terminal event while the worker catches up. + let pending = Arc::clone(&self.queue.lock().pending); + wait_for_emission(&pending, EVENT_LOG_SHUTDOWN_GRACE); + } +} + +#[cfg(not(test))] +fn trace_entry(entry: &Entry) { + let code = entry.event_code; + let message = &entry.message; + let fields = &entry.fields; + match entry.severity { + Severity::Critical | Severity::Error => tracing::error!(?code, %message, ?fields, "Policy audit event"), + Severity::Warning => tracing::warn!(?code, %message, ?fields, "Policy audit event"), + Severity::Notice | Severity::Info | Severity::Debug => { + tracing::info!(?code, %message, ?fields, "Policy audit event"); + } + } +} + +/// The Windows Event Log sink, wrapped in the closure the worker thread owns. +#[cfg(all(not(test), not(debug_assertions)))] +fn event_log_emitter() -> impl FnMut(Entry) + Send + 'static { + let sink: Arc = match sysevent_winevent::WinEvent::new("Devolutions Agent") { + Ok(event_log) => Arc::new(event_log), + Err(error) => { + tracing::error!(%error, "Failed to initialize the Windows Event Log policy audit sink"); + Arc::new(sysevent::NoopSink) + } + }; + move |entry| { + if let Err(error) = sink.emit(entry) { + tracing::warn!(%error, "Failed to emit policy audit event to the Windows Event Log"); + } + } +} + +/// Emits entries in the order they were recorded, until the queue is closed. +#[cfg(any(test, not(debug_assertions)))] +fn event_log_worker( + receiver: &std::sync::mpsc::Receiver<(Entry, EntryClass)>, + admission_pending: &AtomicUsize, + pending: &AtomicUsize, + mut emit: impl FnMut(Entry), +) { + while let Ok((entry, class)) = receiver.recv() { + if class == EntryClass::Admission { + // The entry left the queue, so its slot in the admission budget is free again. + admission_pending.fetch_sub(1, Ordering::Relaxed); + } + emit(entry); + // Counted as emitted only after the sink call, so flushing cannot miss an entry being + // emitted: it is still counted before and after the call. + pending.fetch_sub(1, Ordering::Release); + } +} + +/// Waits, at most for `grace`, until `settled` reports completion, and returns whether it did. +/// +/// The queue worker is a plain thread without a completion signal, so its progress is polled. A +/// sink that stopped making progress would otherwise hold the shutdown indefinitely. +#[cfg(any(test, not(debug_assertions)))] +fn wait_until(settled: impl Fn() -> bool, grace: std::time::Duration) -> bool { + let deadline = std::time::Instant::now() + grace; + while !settled() { + if std::time::Instant::now() >= deadline { + return false; + } + std::thread::sleep(EVENT_LOG_POLL_INTERVAL); + } + true +} + +/// Waits, at most for `grace`, until every accepted entry has been emitted. +/// +/// The worker empties the queue without signalling completion, so this checks the count it +/// decrements. A sink that stopped making progress would otherwise hold the shutdown +/// indefinitely, so giving up is logged rather than waited out. +#[cfg(any(test, not(debug_assertions)))] +fn wait_for_emission(pending: &AtomicUsize, grace: std::time::Duration) { + if !wait_until(|| pending.load(Ordering::Acquire) == 0, grace) { + tracing::warn!( + queued = pending.load(Ordering::Acquire), + "Windows Event Log policy audit entries are still pending; the agent is stopping without waiting for them" + ); + } +} + +struct WriteAuditState { + actor_sid: String, + actor_exe: String, + path: PathBuf, + terminal_recorded: AtomicBool, + recorder: Arc, +} + +impl Drop for WriteAuditState { + fn drop(&mut self) { + if !self.terminal_recorded.swap(true, Ordering::AcqRel) { + self.record( + policy_events::policy_write_denied( + &self.actor_sid, + &self.actor_exe, + INTENT, + &self.path, + DenialReason::RequestRejected.as_str(), + ), + EntryClass::Admission, + ); + } + } +} + +#[derive(Clone)] +pub(crate) struct WriteAudit(Arc); + +impl WriteAudit { + pub(crate) fn begin(actor_sid: &Sid, actor_exe: &Path, path: &Path) -> Self { + Self::begin_with_recorder(actor_sid, actor_exe, path, Arc::clone(recorder())) + } + + fn begin_with_recorder(actor_sid: &Sid, actor_exe: &Path, path: &Path, recorder: Arc) -> Self { + let state = Arc::new(WriteAuditState { + actor_sid: bounded(actor_sid.to_string(), MAX_SID_BYTES), + actor_exe: bounded(actor_exe.display().to_string(), MAX_PATH_BYTES), + path: bounded_path(path), + terminal_recorded: AtomicBool::new(false), + recorder, + }); + state.record( + policy_events::policy_write_attempted(&state.actor_sid, &state.actor_exe, INTENT, &state.path), + EntryClass::Admission, + ); + Self(state) + } + + pub(crate) fn denied(&self, reason: DenialReason) { + // A denial is recorded before the pipe client authenticates, so an unauthenticated flood can + // produce it at will: it yields rather than consuming the capacity reserved for outcomes. + self.finish(EntryClass::Admission, |state| { + policy_events::policy_write_denied(&state.actor_sid, &state.actor_exe, INTENT, &state.path, reason.as_str()) + }); + } + + pub(crate) fn failed(&self, operation: PolicyReplacementOperation, reason: FailureReason) { + self.failed_at(operation, &self.0.path, reason); + } + + pub(crate) fn failed_at(&self, operation: PolicyReplacementOperation, path: &Path, reason: FailureReason) { + let path = bounded_path(path); + let operation_name = operation_name(operation); + let outcome = if reason == FailureReason::StaleStoreToken { + "stale_conflict" + } else { + "failed" + }; + self.finish(EntryClass::Outcome, |state| { + if operation == PolicyReplacementOperation::Create { + policy_events::policy_write_failed( + policy_events::POLICY_CREATE_FAILED, + "Policy creation failed", + &state.actor_sid, + &state.actor_exe, + INTENT, + path, + operation_name, + outcome, + reason.as_str(), + ) + } else { + policy_events::policy_write_failed( + policy_events::POLICY_CHANGE_FAILED, + "Policy change failed", + &state.actor_sid, + &state.actor_exe, + INTENT, + path, + operation_name, + outcome, + reason.as_str(), + ) + } + }); + } + + #[expect( + clippy::too_many_arguments, + reason = "the terminal event records operation and both policy identities" + )] + pub(crate) fn succeeded_at( + &self, + path: &Path, + old_id: Option<&str>, + old_revision: Option, + new_id: &str, + new_revision: u32, + operation: PolicyReplacementOperation, + confirmed_overwrite: bool, + ) { + let path = bounded_path(path); + let old_id = bounded(old_id.unwrap_or("").to_owned(), MAX_POLICY_ID_BYTES); + let old_revision = old_revision.map_or_else(|| "none".to_owned(), |revision| revision.to_string()); + let new_id = bounded(new_id.to_owned(), MAX_POLICY_ID_BYTES); + let operation_name = operation_name(operation); + let outcome = if confirmed_overwrite { + "confirmed_overwrite" + } else { + "applied" + }; + self.finish(EntryClass::Outcome, |state| { + if operation == PolicyReplacementOperation::Create { + policy_events::policy_write_succeeded( + policy_events::POLICY_CREATE_SUCCEEDED, + "Policy creation succeeded", + &state.actor_sid, + &state.actor_exe, + path, + old_id, + old_revision, + new_id, + new_revision, + INTENT, + operation_name, + outcome, + ) + } else { + policy_events::policy_write_succeeded( + policy_events::POLICY_CHANGE_SUCCEEDED, + "Policy change succeeded", + &state.actor_sid, + &state.actor_exe, + path, + old_id, + old_revision, + new_id, + new_revision, + INTENT, + operation_name, + outcome, + ) + } + }); + } + + /// Records the terminal event of `class`, which decides whether a request flood may drop it. + /// + /// A denial never reaches the policy store, so it yields like an attempt; the reserved capacity + /// is kept for the outcome of an authenticated write. + fn finish(&self, class: EntryClass, entry: impl FnOnce(&WriteAuditState) -> Entry) { + if self + .0 + .terminal_recorded + .compare_exchange(false, true, Ordering::AcqRel, Ordering::Acquire) + .is_ok() + { + self.0.record(entry(&self.0), class); + } + } +} + +impl WriteAuditState { + fn record(&self, entry: Entry, class: EntryClass) { + self.recorder.record(entry, class); + } +} + +pub(crate) fn external_change_applied(path: &Path, new_id: &str, new_revision: u32) { + recorder().record( + policy_events::policy_external_change_applied( + bounded_path(path), + bounded(new_id.to_owned(), MAX_POLICY_ID_BYTES), + new_revision, + ), + EntryClass::Outcome, + ); +} + +pub(crate) fn external_change_rejected(path: &Path, state: PolicyManagementState) { + let reason = match state { + PolicyManagementState::Active => "active", + PolicyManagementState::Missing => "missing", + PolicyManagementState::Invalid => "invalid", + }; + recorder().record( + policy_events::policy_external_change_rejected(bounded_path(path), reason), + EntryClass::Outcome, + ); +} + +fn bounded(mut value: String, max_bytes: usize) -> String { + value = value + .chars() + .map(|character| if is_audit_control(character) { ' ' } else { character }) + .collect(); + if value.len() <= max_bytes { + return value; + } + const SUFFIX: &str = "..."; + let mut end = max_bytes - SUFFIX.len(); + while !value.is_char_boundary(end) { + end -= 1; + } + value.truncate(end); + value.push_str(SUFFIX); + value +} + +fn is_audit_control(character: char) -> bool { + character.is_control() + || matches!( + character, + '\u{061c}' | '\u{200e}' | '\u{200f}' | '\u{2028}' | '\u{2029}' | '\u{202a}'..='\u{202e}' | '\u{2066}'..='\u{2069}' + ) +} + +fn bounded_path(path: &Path) -> PathBuf { + PathBuf::from(bounded(path.display().to_string(), MAX_PATH_BYTES)) +} + +const fn operation_name(operation: PolicyReplacementOperation) -> &'static str { + match operation { + PolicyReplacementOperation::Create => "create", + PolicyReplacementOperation::Update => "update", + PolicyReplacementOperation::Repair => "repair", + PolicyReplacementOperation::ReplaceIdentity => "replace_identity", + } +} + +#[cfg(test)] +pub(crate) mod tests { + use super::*; + + std::thread_local! { + static EVENTS: std::cell::RefCell> = const { std::cell::RefCell::new(Vec::new()) }; + } + + pub(crate) struct TestRecorder; + + impl AuditRecorder for TestRecorder { + fn record(&self, entry: Entry, _: EntryClass) { + EVENTS.with(|events| events.borrow_mut().push(entry)); + } + } + + pub(crate) fn take_events() -> Vec { + EVENTS.with(|events| std::mem::take(&mut *events.borrow_mut())) + } + + #[derive(Default)] + pub(crate) struct Recorder(parking_lot::Mutex>); + + impl Recorder { + pub(crate) fn events(&self) -> Vec { + self.0.lock().iter().map(|(entry, _)| entry.clone()).collect() + } + + fn classes(&self) -> Vec { + self.0.lock().iter().map(|(_, class)| *class).collect() + } + } + + impl AuditRecorder for Recorder { + fn record(&self, entry: Entry, class: EntryClass) { + self.0.lock().push((entry, class)); + } + } + + pub(crate) fn begin(actor_sid: &Sid, actor_exe: &Path, path: &Path) -> (WriteAudit, Arc) { + let recorder = Arc::new(Recorder::default()); + let audit = WriteAudit::begin_with_recorder( + actor_sid, + actor_exe, + path, + Arc::clone(&recorder) as Arc, + ); + (audit, recorder) + } + + pub(crate) fn noop() -> WriteAudit { + let sid = Sid::from_well_known(windows::Win32::Security::WinLocalSystemSid, None).expect("SYSTEM SID"); + WriteAudit::begin_with_recorder( + &sid, + Path::new(r"C:\test-client.exe"), + Path::new(r"C:\policy.json"), + Arc::new(NoopRecorder), + ) + } + + struct NoopRecorder; + + impl AuditRecorder for NoopRecorder { + fn record(&self, _: Entry, _: EntryClass) {} + } + + /// Records which shutdown the recorder was asked for. + #[derive(Default)] + struct ShutdownRecorder(parking_lot::Mutex>); + + impl AuditRecorder for ShutdownRecorder { + fn record(&self, _: Entry, _: EntryClass) {} + + fn drain(&self) { + self.0.lock().push("drain"); + } + + fn flush(&self) { + self.0.lock().push("flush"); + } + } + + fn test_audit() -> (WriteAudit, Arc) { + let sid = Sid::from_well_known(windows::Win32::Security::WinLocalSystemSid, None).expect("SYSTEM SID"); + begin(&sid, Path::new(r"C:\client.exe"), Path::new(r"C:\policy.json")) + } + + #[test] + fn attempt_precedes_denial_and_only_one_terminal_event_is_recorded() { + let (audit, recorder) = test_audit(); + audit.denied(DenialReason::AuthenticationFailed); + audit.failed(PolicyReplacementOperation::Update, FailureReason::InvalidPolicy); + assert_eq!( + recorder + .events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [ + Some(policy_events::POLICY_WRITE_ATTEMPTED), + Some(policy_events::POLICY_WRITE_DENIED) + ] + ); + } + + #[test] + fn a_denial_yields_like_an_attempt_while_an_outcome_keeps_the_reserve() { + // A denial is reachable before the pipe client authenticates, so an unauthenticated flood + // must be unable to spend the capacity reserved for the outcome of an accepted write. + let (denied, recorder) = test_audit(); + denied.denied(DenialReason::AuthenticationFailed); + assert_eq!(recorder.classes(), [EntryClass::Admission, EntryClass::Admission]); + + let (abandoned, recorder) = test_audit(); + drop(abandoned); + assert_eq!(recorder.classes(), [EntryClass::Admission, EntryClass::Admission]); + + let (failed, recorder) = test_audit(); + failed.failed(PolicyReplacementOperation::Update, FailureReason::InvalidPolicy); + assert_eq!(recorder.classes(), [EntryClass::Admission, EntryClass::Outcome]); + } + + #[test] + fn abandoned_clones_record_one_terminal_denial() { + let (audit, recorder) = test_audit(); + let retained = audit.clone(); + drop(audit); + assert_eq!(recorder.events().len(), 1); + drop(retained); + let events = recorder.events(); + assert_eq!(events.len(), 2); + assert_eq!(events[1].event_code, Some(policy_events::POLICY_WRITE_DENIED)); + assert!( + events[1] + .fields + .iter() + .any(|(name, value)| name == "reason" && value == "request_rejected") + ); + } + + #[test] + fn terminal_outcomes_are_reserved_against_an_admission_flood() { + // A worker that cannot make progress leaves the queue in its saturated state. + let open = Arc::new(AtomicBool::new(false)); + let release = Arc::clone(&open); + let (emitted, received) = std::sync::mpsc::channel(); + let mut queue = EventLogQueue::start(move |entry| { + while !release.load(Ordering::Acquire) { + std::thread::sleep(std::time::Duration::from_millis(1)); + } + let _ = emitted.send(entry); + }) + .expect("the audit worker starts"); + + let admission = + || Entry::new("Policy management write attempted").event_code(policy_events::POLICY_WRITE_ATTEMPTED); + let outcome = + Entry::new("Policy management change succeeded").event_code(policy_events::POLICY_CHANGE_SUCCEEDED); + + let mut admitted = 0; + let mut refused = 0; + for _ in 0..EVENT_LOG_ADMISSION_BUDGET + 8 { + if queue.record(admission(), EntryClass::Admission).is_ok() { + admitted += 1; + } else { + refused += 1; + } + } + assert!(admitted >= EVENT_LOG_ADMISSION_BUDGET); + assert!(refused > 0, "the flood must saturate the admission budget"); + + // The outcome is still accepted, because the outcome reserve is out of reach of the flood. + queue + .record(outcome, EntryClass::Outcome) + .expect("a terminal outcome is accepted while admission entries are refused"); + + open.store(true, Ordering::Release); + queue.drain(); + assert_eq!( + queue.admission_pending.load(Ordering::Relaxed), + 0, + "every admitted entry released its slot in the admission budget" + ); + + // Every admitted entry reached the sink, plus the outcome that the flood could not displace. + let codes = received.iter().map(|entry| entry.event_code).collect::>(); + assert_eq!(codes.len(), admitted + 1); + assert_eq!( + codes + .iter() + .filter(|code| **code == Some(policy_events::POLICY_CHANGE_SUCCEEDED)) + .count(), + 1 + ); + } + + #[test] + fn an_accepted_attempt_precedes_its_terminal_outcome() { + // The worker blocks on the first entry it takes, so the attempt and its outcome are both + // queued while it cannot make progress, and the emitted order is the recorded order. + let busy = Arc::new(AtomicBool::new(false)); + let open = Arc::new(AtomicBool::new(false)); + let started = Arc::clone(&busy); + let release = Arc::clone(&open); + let (emitted, received) = std::sync::mpsc::channel(); + let mut queue = EventLogQueue::start(move |entry| { + started.store(true, Ordering::Release); + while !release.load(Ordering::Acquire) { + std::thread::sleep(std::time::Duration::from_millis(1)); + } + let _ = emitted.send(entry); + }) + .expect("the audit worker starts"); + + queue + .record( + // The terminal outcome of a previous write, which the worker takes and emits first. + Entry::new("Policy management change failed").event_code(policy_events::POLICY_CHANGE_FAILED), + EntryClass::Outcome, + ) + .expect("the blocking outcome is accepted"); + while !busy.load(Ordering::Acquire) { + std::thread::sleep(std::time::Duration::from_millis(1)); + } + + queue + .record( + Entry::new("Policy management write attempted").event_code(policy_events::POLICY_WRITE_ATTEMPTED), + EntryClass::Admission, + ) + .expect("the attempt is accepted"); + queue + .record( + Entry::new("Policy management change succeeded").event_code(policy_events::POLICY_CHANGE_SUCCEEDED), + EntryClass::Outcome, + ) + .expect("the terminal outcome is accepted"); + + open.store(true, Ordering::Release); + queue.drain(); + + let codes = received.iter().map(|entry| entry.event_code).collect::>(); + assert_eq!( + codes, + [ + Some(policy_events::POLICY_CHANGE_FAILED), + Some(policy_events::POLICY_WRITE_ATTEMPTED), + Some(policy_events::POLICY_CHANGE_SUCCEEDED) + ] + ); + } + + #[test] + fn audit_text_removes_control_characters_before_truncation() { + let value = format!( + "injected\r\n\t\0\u{061c}\u{200e}\u{200f}\u{2028}\u{2029}\u{202a}\u{202b}\u{202c}\u{202d}\u{202e}\u{2066}\u{2067}\u{2068}\u{2069}{}", + "é".repeat(MAX_POLICY_ID_BYTES) + ); + let bounded = bounded(value, MAX_POLICY_ID_BYTES); + assert!(bounded.len() <= MAX_POLICY_ID_BYTES); + assert!(bounded.ends_with("...")); + assert!(!bounded.chars().any(is_audit_control)); + } + + #[test] + fn audit_values_are_bounded_and_fields_are_allowlisted() { + let sid = Sid::from_well_known(windows::Win32::Security::WinLocalSystemSid, None).expect("SYSTEM SID"); + let long = "é".repeat(MAX_PATH_BYTES); + let (audit, recorder) = begin(&sid, Path::new(&long), Path::new(&long)); + audit.succeeded_at( + Path::new(&long), + Some(&long), + Some(1), + &long, + 2, + PolicyReplacementOperation::Update, + false, + ); + + let events = recorder.events(); + let entry = &events[1]; + assert!(entry.fields.iter().all(|(name, value)| { + matches!( + name.as_str(), + "actor_sid" + | "actor_exe" + | "intent" + | "path" + | "old_id" + | "old_revision" + | "new_id" + | "new_revision" + | "operation" + | "outcome" + ) && value.len() <= MAX_PATH_BYTES + })); + for forbidden in ["body", "draft", "policy", "receipt", "store_token"] { + assert!(!entry.fields.iter().any(|(name, _)| name == forbidden)); + } + } + + #[test] + fn terminal_event_codes_follow_the_replacement_operation() { + for (operation, failure_code, success_code) in [ + ( + PolicyReplacementOperation::Create, + policy_events::POLICY_CREATE_FAILED, + policy_events::POLICY_CREATE_SUCCEEDED, + ), + ( + PolicyReplacementOperation::Update, + policy_events::POLICY_CHANGE_FAILED, + policy_events::POLICY_CHANGE_SUCCEEDED, + ), + ( + PolicyReplacementOperation::Repair, + policy_events::POLICY_CHANGE_FAILED, + policy_events::POLICY_CHANGE_SUCCEEDED, + ), + ( + PolicyReplacementOperation::ReplaceIdentity, + policy_events::POLICY_CHANGE_FAILED, + policy_events::POLICY_CHANGE_SUCCEEDED, + ), + ] { + let (failed, failed_recorder) = test_audit(); + failed.failed(operation, FailureReason::StaleStoreToken); + assert_eq!(failed_recorder.events()[1].event_code, Some(failure_code)); + + let (succeeded, succeeded_recorder) = test_audit(); + succeeded.succeeded_at(Path::new(r"C:\policy.json"), None, None, "new", 1, operation, true); + assert_eq!(succeeded_recorder.events()[1].event_code, Some(success_code)); + } + } + + #[test] + fn a_lease_holds_the_recorder_open_until_the_last_one_is_dropped() { + static PRODUCERS: AtomicUsize = AtomicUsize::new(0); + + let lease = AuditLease::acquire_on(&PRODUCERS); + assert_eq!(PRODUCERS.load(Ordering::Acquire), 1); + + let nested = AuditLease::acquire_on(&PRODUCERS); + drop(lease); + assert_eq!( + PRODUCERS.load(Ordering::Acquire), + 1, + "a connection can only record while it holds a lease" + ); + + drop(nested); + assert_eq!(PRODUCERS.load(Ordering::Acquire), 0); + } + + #[test] + fn a_live_producer_makes_the_shutdown_flush_instead_of_closing_the_queue() { + let recorder = ShutdownRecorder(parking_lot::Mutex::new(Vec::new())); + shutdown(&recorder, 1); + assert_eq!(*recorder.0.lock(), ["flush"]); + + let recorder = ShutdownRecorder(parking_lot::Mutex::new(Vec::new())); + shutdown(&recorder, 0); + assert_eq!(*recorder.0.lock(), ["drain"]); + } + + #[test] + fn a_flushed_queue_still_accepts_the_terminal_event_of_a_live_producer() { + let (emitted, received) = std::sync::mpsc::channel(); + let mut queue = EventLogQueue::start(move |entry| { + let _ = emitted.send(entry); + }) + .expect("the audit worker starts"); + + queue + .record( + Entry::new("Policy management write attempted").event_code(policy_events::POLICY_WRITE_ATTEMPTED), + EntryClass::Admission, + ) + .expect("the attempt is accepted"); + wait_for_emission(&queue.pending, EVENT_LOG_SHUTDOWN_GRACE); + assert_eq!( + queue.pending.load(Ordering::Acquire), + 0, + "flushing waits for every accepted entry to reach the sink" + ); + + // The connection that is still finishing its policy write records its terminal event here. + queue + .record( + Entry::new("Policy management change succeeded").event_code(policy_events::POLICY_CHANGE_SUCCEEDED), + EntryClass::Outcome, + ) + .expect("a flush leaves the queue accepting"); + queue.drain(); + + let codes = received.iter().map(|entry| entry.event_code).collect::>(); + assert_eq!( + codes, + [ + Some(policy_events::POLICY_WRITE_ATTEMPTED), + Some(policy_events::POLICY_CHANGE_SUCCEEDED) + ] + ); + } + + #[test] + fn flushing_gives_up_on_a_sink_that_stopped_making_progress() { + let pending = AtomicUsize::new(1); + let started = std::time::Instant::now(); + + wait_for_emission(&pending, std::time::Duration::from_millis(50)); + assert!(started.elapsed() >= std::time::Duration::from_millis(50)); + assert_eq!( + pending.load(Ordering::Acquire), + 1, + "the entry stays queued for the worker" + ); + + pending.store(0, Ordering::Release); + let flushed = std::time::Instant::now(); + wait_for_emission(&pending, std::time::Duration::from_secs(5)); + assert!(flushed.elapsed() < std::time::Duration::from_secs(1)); + } + + #[test] + fn closing_the_queue_gives_up_on_a_sink_that_stopped_making_progress() { + let open = Arc::new(AtomicBool::new(false)); + let release = Arc::clone(&open); + let entered = Arc::new(AtomicBool::new(false)); + let sink_entered = Arc::clone(&entered); + let mut queue = EventLogQueue::start(move |_| { + sink_entered.store(true, Ordering::Release); + while !release.load(Ordering::Acquire) { + std::thread::sleep(std::time::Duration::from_millis(1)); + } + }) + .expect("the audit worker starts"); + + queue + .record( + Entry::new("Policy management write attempted").event_code(policy_events::POLICY_WRITE_ATTEMPTED), + EntryClass::Admission, + ) + .expect("the attempt is accepted"); + while !entered.load(Ordering::Acquire) { + std::thread::sleep(std::time::Duration::from_millis(1)); + } + + let closing = std::time::Instant::now(); + queue.drain_with_grace(std::time::Duration::from_millis(50)); + assert!( + closing.elapsed() < std::time::Duration::from_secs(2), + "closing the queue does not wait for a sink that stopped making progress" + ); + + // The detached worker holds nothing the process needs, so releasing the sink lets it emit the + // entry it took and then exit. + open.store(true, Ordering::Release); + } +} diff --git a/crates/now-package-broker/src/auth.rs b/crates/now-package-broker/src/auth.rs index d891f6351..d647e750c 100644 --- a/crates/now-package-broker/src/auth.rs +++ b/crates/now-package-broker/src/auth.rs @@ -222,6 +222,10 @@ impl PipeClient { &self.user_sid } + pub(crate) fn executable_path(&self) -> &Path { + &self.executable_path + } + pub(crate) fn is_elevated_administrator(&self) -> bool { self.is_elevated && self.is_administrator } diff --git a/crates/now-package-broker/src/lib.rs b/crates/now-package-broker/src/lib.rs index e1542dda4..f8acf7e70 100644 --- a/crates/now-package-broker/src/lib.rs +++ b/crates/now-package-broker/src/lib.rs @@ -5,6 +5,8 @@ //! //! The broker is only functional on Windows; on other platforms this crate is empty. +#[cfg(windows)] +mod audit; #[cfg(windows)] mod auth; #[cfg(windows)] diff --git a/crates/now-package-broker/src/pipe.rs b/crates/now-package-broker/src/pipe.rs index 6a4c51b00..88721a675 100644 --- a/crates/now-package-broker/src/pipe.rs +++ b/crates/now-package-broker/src/pipe.rs @@ -42,8 +42,38 @@ const MAX_CONCURRENT_CONNECTIONS: usize = 16; /// request would each pin a connection slot indefinitely and could exhaust the pool. const CONNECTION_DEADLINE: std::time::Duration = std::time::Duration::from_secs(30); +/// How long shutdown waits for the connections that are still serving a request, then for the +/// aborted ones to actually stop. +/// +/// A healthy exchange completes in milliseconds, and each connection is already bounded by +/// `CONNECTION_DEADLINE`, so this only has to cover the tail of a request already in progress; +/// connections still stuck at the end of it are aborted rather than allowed to hold the shutdown. +/// The same budget then bounds the wait for those aborts to take effect, so a connection stuck in +/// synchronous work costs the shutdown one grace period. Each connection holds an audit lease for +/// its whole lifetime, so the queued events of a connection the shutdown gave up on are flushed +/// instead of being dropped (see [`crate::audit::AuditLease`]). +const CONNECTION_SHUTDOWN_GRACE: std::time::Duration = std::time::Duration::from_secs(5); + /// Start the named pipe server and accept connections until shutdown. pub async fn run_pipe_server(state: Arc, shutdown: CancellationToken) -> anyhow::Result<()> { + // Serving a connection can record policy audit events, and the caller stops the audit recorder + // as soon as this function returns, so a connection that outlives it must be known to the + // recorder. Each connection holds an audit lease for as long as it can record, which keeps its + // terminal event from being rejected. The accept loop runs in its own function, so that every + // one of its exit paths, including a failure to create the next pipe instance, reaches the + // drain below instead of returning straight out. + let mut connections = tokio::task::JoinSet::new(); + let result = accept_connections(&state, &shutdown, &mut connections).await; + + drain_after_accept_loop(&mut connections, CONNECTION_SHUTDOWN_GRACE, result).await +} + +/// Accept connections until `shutdown` is cancelled or the next pipe instance cannot be created. +async fn accept_connections( + state: &Arc, + shutdown: &CancellationToken, + connections: &mut tokio::task::JoinSet<()>, +) -> anyhow::Result<()> { let pipe_name = state.pipe_name.clone(); info!(%pipe_name, "Starting named pipe server"); @@ -51,16 +81,17 @@ pub async fn run_pipe_server(state: Arc, shutdown: CancellationToke let mut first_instance = true; loop { + // Reap the connections that already finished, so completed tasks do not accumulate here + // for the lifetime of the process. + while connections.try_join_next().is_some() {} + // Wait for a free connection slot before exposing a new pipe instance, // bounding the number of concurrently served connections. let permit = tokio::select! { permit = Arc::clone(&connection_permits).acquire_owned() => { permit.expect("the semaphore is never closed") } - _ = shutdown.cancelled() => { - info!("Pipe server shutting down"); - return Ok(()); - } + _ = shutdown.cancelled() => break, }; // Create a new pipe instance for each connection. @@ -71,8 +102,13 @@ pub async fn run_pipe_server(state: Arc, shutdown: CancellationToke result = server.connect() => { match result { Ok(()) => { - let state = Arc::clone(&state); - tokio::spawn(async move { + let state = Arc::clone(state); + connections.spawn(async move { + // Serving this connection can commit a policy and record its terminal + // event, which is blocking work the shutdown cannot interrupt, so the + // lease keeps the recorder from closing the queue under that event. + let _audit_lease = crate::audit::AuditLease::acquire(); + let serve = async move { // Keep blocking unauthenticated capture off the accept loop and // retain the connection slot until the work actually completes. @@ -113,10 +149,50 @@ pub async fn run_pipe_server(state: Arc, shutdown: CancellationToke } } } - _ = shutdown.cancelled() => { - info!("Pipe server shutting down"); - return Ok(()); - } + _ = shutdown.cancelled() => break, + } + } + + info!("Pipe server shutting down"); + + Ok(()) +} + +/// Drain the connections the accept loop spawned, then report what the loop returned. +/// +/// An accept loop that fails after accepting a connection has to wait for that connection too, +/// rather than let the `?` on the failing call drop the set and abandon a served request mid-flight. +async fn drain_after_accept_loop( + connections: &mut tokio::task::JoinSet<()>, + grace: std::time::Duration, + loop_result: anyhow::Result<()>, +) -> anyhow::Result<()> { + wait_for_connections(connections, grace).await; + + loop_result +} + +/// Wait for the connection tasks to finish, then abort the ones that outlive the grace. +/// +/// Waiting is bounded on both sides: a task inside synchronous work, such as authenticating a +/// client or writing the policy storage, never reaches a cancellation point, so the settle after +/// the abort cannot be left unbounded either. A connection given up on here holds an audit lease, +/// so the recorder flushes its queued events and keeps accepting, rather than closing the queue +/// under the terminal event of the policy write that connection is still finishing. The agent +/// gives the whole shutdown a fixed budget before it stops the runtime. +async fn wait_for_connections(connections: &mut tokio::task::JoinSet<()>, grace: std::time::Duration) { + let drained = tokio::time::timeout(grace, async { while connections.join_next().await.is_some() {} }).await; + + if drained.is_err() { + warn!("Aborted named pipe connections still serving at shutdown"); + connections.abort_all(); + + let settled = tokio::time::timeout(grace, async { while connections.join_next().await.is_some() {} }).await; + + if settled.is_err() { + error!( + "Named pipe connections are still running blocking work; their policy audit events may not reach the Windows Event Log before the agent stops the process" + ); } } } @@ -195,11 +271,17 @@ fn build_pipe_security_attributes() -> anyhow::Result); + + impl Drop for DropFlag { + fn drop(&mut self) { + self.0.store(true, Ordering::SeqCst); + } + } + + #[tokio::test(flavor = "multi_thread", worker_threads = 2)] + async fn shutdown_waits_for_the_connections_that_are_still_serving() { + let release = CancellationToken::new(); + let mut connections = JoinSet::new(); + connections.spawn({ + let release = release.clone(); + async move { release.cancelled().await } + }); + + let waited = tokio::spawn(async move { + wait_for_connections(&mut connections, Duration::from_secs(30)).await; + }); + tokio::time::sleep(Duration::from_millis(100)).await; + assert!( + !waited.is_finished(), + "the wait must last as long as a connection is being served" + ); + + release.cancel(); + tokio::time::timeout(Duration::from_secs(5), waited) + .await + .expect("the wait completes once the connection is done") + .expect("the wait task does not panic"); + } + + #[tokio::test(flavor = "multi_thread", worker_threads = 2)] + async fn shutdown_aborts_the_connections_that_outlive_the_grace() { + let dropped = Arc::new(AtomicBool::new(false)); + let mut connections = JoinSet::new(); + connections.spawn({ + let dropped = Arc::clone(&dropped); + async move { + let _flag = DropFlag(dropped); + std::future::pending::<()>().await; + } + }); + + let started = Instant::now(); + wait_for_connections(&mut connections, Duration::from_millis(200)).await; + + assert!( + started.elapsed() >= Duration::from_millis(200), + "the grace must elapse first" + ); + assert!(dropped.load(Ordering::SeqCst), "the connection task must be aborted"); + assert!(connections.is_empty(), "no connection task may outlive shutdown"); + } + + #[tokio::test(flavor = "multi_thread", worker_threads = 4)] + async fn shutdown_gives_up_on_a_connection_stuck_in_blocking_work() { + // A connection inside synchronous work, such as authenticating a client or reading the + // policy storage, never reaches a cancellation point, so aborting it does not stop it. + // The wait still has to return, because the caller drains the audit queue right after. + let mut connections = JoinSet::new(); + connections.spawn(async { + tokio::task::block_in_place(|| std::thread::sleep(NON_ABORTABLE_CONNECTION_WORK)); + }); + + let started = Instant::now(); + wait_for_connections(&mut connections, Duration::from_millis(200)).await; + + // Returning with the task still in the set is the regression: an unbounded settle only + // returns once every connection has finished. + assert!( + !connections.is_empty(), + "the wait must not be held by a connection that cannot be aborted" + ); + assert!( + started.elapsed() < NON_ABORTABLE_CONNECTION_WORK, + "the wait must return long before the blocking work is over" + ); + } + + #[tokio::test(flavor = "multi_thread", worker_threads = 2)] + async fn an_accept_loop_failure_waits_for_the_connections_it_accepted() { + // Mirrors `create_pipe_instance` failing after a connection was accepted: the error may + // reach the caller only once no connection can still record an audit event. + let dropped = Arc::new(AtomicBool::new(false)); + let mut connections = JoinSet::new(); + connections.spawn({ + let dropped = Arc::clone(&dropped); + async move { + let _flag = DropFlag(dropped); + std::future::pending::<()>().await; + } + }); + + let started = Instant::now(); + let result = drain_after_accept_loop( + &mut connections, + Duration::from_millis(200), + Err(anyhow::anyhow!("failed to create the next pipe instance")), + ) + .await; + + assert!(result.is_err(), "the accept loop failure is still reported"); + assert!( + started.elapsed() >= Duration::from_millis(200), + "the accepted connections have to settle first" + ); + assert!(dropped.load(Ordering::SeqCst), "the connection task must be aborted"); + assert!(connections.is_empty(), "no connection task may outlive the accept loop"); + } + #[tokio::test] async fn completed_capture_returns_its_permit_to_the_connection_task() { let permits = Arc::new(Semaphore::new(1)); diff --git a/crates/now-package-broker/src/policy_store/mod.rs b/crates/now-package-broker/src/policy_store/mod.rs index 631025078..74f947431 100644 --- a/crates/now-package-broker/src/policy_store/mod.rs +++ b/crates/now-package-broker/src/policy_store/mod.rs @@ -9,9 +9,9 @@ use chrono::Utc; use now_policy::PolicyDocument; use now_policy_api::{ API_VERSION_STR, ErrorCode, ErrorResponse, ErrorResponseKind, InvalidPolicyDiagnostics, PolicyConfigurationSource, - PolicyManagementSnapshot, PolicyManagementState, PolicyReadOnlyReason, PolicyReplacementOperation, - PolicyReplacementRequest, PolicyStoreToken, PolicyValidationResult, PolicyWriteCapability, ServerContext, - Transport, + PolicyConflictHandling, PolicyManagementSnapshot, PolicyManagementState, PolicyReadOnlyReason, + PolicyReplacementOperation, PolicyReplacementRequest, PolicyStoreToken, PolicyValidationResult, + PolicyWriteCapability, ServerContext, Transport, }; mod receipt; @@ -255,7 +255,7 @@ impl PolicyStore { return self.management_snapshot(); } let (_, observation) = self.observe_storage(false); - let management = self.publish_observation(observation); + let management = self.publish_external_observation(observation); tracing::info!(?cause, state = ?management.state, "Reloaded package broker policy"); management } @@ -265,8 +265,10 @@ impl PolicyStore { if *monitoring != Monitoring::Initializing { return self.management_snapshot(); } + // The watcher reports ready after the provisional load, so a policy that changed in between + // is an external change and must be audited as one. let (_, observation) = self.observe_storage(false); - let management = self.publish_observation(observation); + let management = self.publish_external_observation(observation); *monitoring = Monitoring::Available; management } @@ -294,9 +296,15 @@ impl PolicyStore { self.publish_observation(observation); } - pub async fn replace(&self, request: PolicyReplacementRequest) -> Result { + pub(crate) async fn replace( + &self, + request: PolicyReplacementRequest, + audit: crate::audit::WriteAudit, + ) -> Result { + let operation = request.operation; let monitoring = self.writer.lock().await; if *monitoring != Monitoring::Available { + audit.failed(operation, crate::audit::FailureReason::MonitoringUnavailable); return Err(error_with_management( ErrorCode::BrokerPaused, "policy change monitoring is unavailable", @@ -310,7 +318,9 @@ impl PolicyStore { // Both conflict modes require this exact token. // ConfirmOverwrite records retry intent without retaining token history. if fresh_token != request.expected_store_token { - let management = self.publish_observation(observation); + let audit_path = observation.canonical_path.clone(); + let management = self.publish_external_observation(observation); + audit.failed_at(operation, &audit_path, crate::audit::FailureReason::StaleStoreToken); return Err(error_with_management( ErrorCode::StalePolicyStoreToken, "the configured policy changed after the supplied store token was observed", @@ -319,6 +329,11 @@ impl PolicyStore { } if observation.write_capability != PolicyWriteCapability::Writable { + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::PathNotWritable, + ); let code = match observation.read_only_reason { Some(PolicyReadOnlyReason::UnsupportedFileSystem) => ErrorCode::UnsupportedPolicyFilesystem, Some(PolicyReadOnlyReason::UnsupportedFormat) => ErrorCode::UnsupportedPolicyFormat, @@ -329,6 +344,11 @@ impl PolicyStore { let validation = self.validate_draft(&request.draft); if !validation.is_valid { + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::InvalidPolicy, + ); return Err(error_with_validation( ErrorCode::InvalidPolicy, "the submitted draft failed authoritative validation", @@ -345,35 +365,61 @@ impl PolicyStore { &validation.findings, &request.validation_receipt, ) { + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::InvalidReceipt, + ); return Err(error_with_validation( ErrorCode::ValidationFailed, "the validation receipt does not match this draft", validation, )); } - if !validation.findings.is_empty() && !request.warnings_acknowledged { - return Err(error_with_validation( - ErrorCode::WarningConfirmationRequired, - "validation warnings must be explicitly acknowledged", - validation, - )); - } - - let revision = plan_revision( + let revision = match plan_revision( request.operation, observation.state, observation.policy.as_ref(), &draft.metadata.id.0, - ) - .map_err(|message| error_response(ErrorCode::Conflict, message))?; - let policy = draft.into_policy_document(revision, Utc::now()).map_err(|_| { - error_response( - ErrorCode::ValidationFailed, - "failed to commit the validated policy draft", - ) - })?; - let bytes = serde_json::to_vec_pretty(&policy) - .map_err(|_| error_response(ErrorCode::InternalError, "failed to serialize the committed policy"))?; + ) { + Ok(revision) => revision, + Err(message) => { + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::RevisionConflict, + ); + return Err(error_response(ErrorCode::Conflict, message)); + } + }; + let policy = match draft.into_policy_document(revision, Utc::now()) { + Ok(policy) => policy, + Err(_) => { + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::DraftCommitFailed, + ); + return Err(error_response( + ErrorCode::ValidationFailed, + "failed to commit the validated policy draft", + )); + } + }; + let bytes = match serde_json::to_vec_pretty(&policy) { + Ok(bytes) => bytes, + Err(_) => { + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::SerializationFailed, + ); + return Err(error_response( + ErrorCode::InternalError, + "failed to serialize the committed policy", + )); + } + }; let persisted = if request.operation == PolicyReplacementOperation::Create { self.storage @@ -388,13 +434,20 @@ impl PolicyStore { tracing::warn!(error = format!("{error:#}"), "Policy persistence failed"); let (_, current) = self.observe_storage(false); if current.fingerprint != observation.fingerprint { - let management = self.publish_observation(current); + let audit_path = current.canonical_path.clone(); + let management = self.publish_external_observation(current); + audit.failed_at(operation, &audit_path, crate::audit::FailureReason::StaleStoreToken); return Err(error_with_management( ErrorCode::StalePolicyStoreToken, "the policy storage changed before publication; retry with the current store token", management, )); } + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::PersistenceFailed, + ); return Err(error_response( ErrorCode::PolicyPersistenceFailed, "failed to persist the policy", @@ -407,12 +460,19 @@ impl PolicyStore { ); let (_, current) = self.observe_storage(false); if current.fingerprint == observation.fingerprint { + audit.failed_at( + operation, + &observation.canonical_path, + crate::audit::FailureReason::ConditionalPublicationFailed, + ); return Err(error_response( ErrorCode::PolicyPersistenceFailed, "failed to conditionally persist the policy", )); } - let management = self.publish_observation(current); + let audit_path = current.canonical_path.clone(); + let management = self.publish_external_observation(current); + audit.failed_at(operation, &audit_path, crate::audit::FailureReason::StaleStoreToken); return Err(error_with_management( ErrorCode::StalePolicyStoreToken, "the policy storage changed during publication; retry with the current store token", @@ -425,7 +485,18 @@ impl PolicyStore { "Published policy failed authoritative reload" ); let (_, current) = self.observe_storage(false); - let management = self.publish_observation(current); + let audit_path = current.canonical_path.clone(); + // The publication is this request's own content, so a difference the reload reports + // afterwards is this write rather than an external change -- but only while the + // storage still holds the document this request committed. An administrator may + // replace the policy between publication and this re-observation, and that + // replacement must be audited as an external change instead of being absorbed. + let management = if holds_published_document(¤t, &policy) { + self.publish_observation(current) + } else { + self.publish_external_observation(current) + }; + audit.failed_at(operation, &audit_path, crate::audit::FailureReason::ActivationFailed); return Err(error_with_management( ErrorCode::PolicyActivationFailed, "the policy was published but failed authoritative reload", @@ -434,6 +505,9 @@ impl PolicyStore { } }; + let old_id = observation.policy.as_ref().map(|policy| policy.metadata.id.0.clone()); + let old_revision = observation.policy.as_ref().map(|policy| policy.metadata.revision); + let canonical_path = observation.canonical_path.clone(); let token = token_for(&previous, &persisted.fingerprint); let snapshot = Arc::new(Snapshot { state: PolicyManagementState::Active, @@ -447,6 +521,16 @@ impl PolicyStore { }); *self.snapshot.write().expect("policy store snapshot lock poisoned") = snapshot; + audit.succeeded_at( + &canonical_path, + old_id.as_deref(), + old_revision, + &persisted.policy.metadata.id.0, + persisted.policy.metadata.revision, + operation, + request.conflict_handling == PolicyConflictHandling::ConfirmOverwrite, + ); + Ok(ReplaceSuccess { policy: persisted.policy, validation, @@ -469,6 +553,34 @@ impl PolicyStore { management } + fn publish_external_observation(&self, observation: Observation) -> PolicyManagementSnapshot { + let policy_changed = self.snapshot().fingerprint != observation.fingerprint; + let management = self.publish_observation(observation); + if policy_changed { + let path = Path::new(&management.configured_path); + match (management.state, management.policy.as_ref()) { + (PolicyManagementState::Active, Some(policy)) => { + crate::audit::external_change_applied(path, &policy.metadata.id.0, policy.metadata.revision); + } + (PolicyManagementState::Missing | PolicyManagementState::Invalid, _) => { + crate::audit::external_change_rejected(path, management.state); + } + (PolicyManagementState::Active, None) => { + crate::audit::external_change_rejected(path, PolicyManagementState::Invalid); + } + } + } + management + } + + #[cfg(test)] + pub(crate) async fn replace_for_tests( + &self, + request: PolicyReplacementRequest, + ) -> Result { + self.replace(request, crate::audit::tests::noop()).await + } + #[cfg(test)] pub(crate) fn for_tests(policy: Option) -> Arc { let storage = Arc::new(TestStorage::new(policy)); @@ -602,6 +714,21 @@ fn error_with_management( response } +/// Whether a re-observed storage state still holds the document a request just published. +/// +/// Documents never compare equal by identity alone: an administrator can write a modified document +/// that keeps the publication's id and revision, so both sides are compared as serialized values, +/// exactly as the authoritative reload the storage performs after its own write. +fn holds_published_document(observation: &Observation, published: &PolicyDocument) -> bool { + let Some(current) = observation.policy.as_ref() else { + return false; + }; + match (serde_json::to_value(current), serde_json::to_value(published)) { + (Ok(current), Ok(published)) => current == published, + _ => false, + } +} + #[cfg(test)] fn observe_file(source: PolicyConfigurationSource, path: &Path) -> Observation { windows::observe(source, path, &windows::AtomicityProbeCache::new()) @@ -614,7 +741,9 @@ struct TestStorage { fail_concurrent_check: std::sync::atomic::AtomicBool, fail_target_retention: std::sync::atomic::AtomicBool, race_before_persist: parking_lot::Mutex>, + race_after_persist: parking_lot::Mutex>, post_persist_capability: parking_lot::Mutex)>>, + fail_after_publication: std::sync::atomic::AtomicBool, persisted_configured_paths: parking_lot::Mutex>, } @@ -627,7 +756,9 @@ impl TestStorage { fail_concurrent_check: std::sync::atomic::AtomicBool::new(false), fail_target_retention: std::sync::atomic::AtomicBool::new(false), race_before_persist: parking_lot::Mutex::new(None), + race_after_persist: parking_lot::Mutex::new(None), post_persist_capability: parking_lot::Mutex::new(None), + fail_after_publication: std::sync::atomic::AtomicBool::new(false), persisted_configured_paths: parking_lot::Mutex::new(Vec::new()), } } @@ -639,7 +770,9 @@ impl TestStorage { fail_concurrent_check: std::sync::atomic::AtomicBool::new(false), fail_target_retention: std::sync::atomic::AtomicBool::new(false), race_before_persist: parking_lot::Mutex::new(None), + race_after_persist: parking_lot::Mutex::new(None), post_persist_capability: parking_lot::Mutex::new(None), + fail_after_publication: std::sync::atomic::AtomicBool::new(false), persisted_configured_paths: parking_lot::Mutex::new(Vec::new()), } } @@ -651,6 +784,19 @@ impl TestStorage { fn race_before_next_persist(&self, policy: PolicyDocument) { *self.race_before_persist.lock() = Some(policy); } + + /// Makes the next `persist` publish the request's content, then replace it on disk with + /// `replacement` and report activation failure -- an administrator writing the file in the + /// window between publication and the authoritative reload. + fn race_after_next_publication(&self, replacement: Observation) { + *self.race_after_persist.lock() = Some(replacement); + } + + /// Makes the next `persist` report activation failure after the content was published. + fn fail_after_next_publication(&self) { + self.fail_after_publication + .store(true, std::sync::atomic::Ordering::SeqCst); + } } #[cfg(test)] @@ -736,6 +882,20 @@ impl TestStorage { next.fingerprint = DiskFingerprint::test_active(bytes, 2, 1, 1, 2); } *self.observation.lock() = clone_observation(&next); + if let Some(replacement) = self.race_after_persist.lock().take() { + *self.observation.lock() = replacement; + return Err(WriteFailure::PostPublication(anyhow::anyhow!( + "injected external policy replacement after publication" + ))); + } + if self + .fail_after_publication + .swap(false, std::sync::atomic::Ordering::SeqCst) + { + return Err(WriteFailure::PostPublication(anyhow::anyhow!( + "injected post-publication activation failure" + ))); + } Ok(PersistedPolicy { policy, fingerprint: next.fingerprint, @@ -809,6 +969,7 @@ fn clone_observation(observation: &Observation) -> Observation { mod storage_tests { use now_policy::PolicyDraftDocument; use now_policy_api::{PolicyConflictHandling, PolicyReplacementRequestKind}; + use win_api_wrappers::identity::sid::Sid; use super::*; @@ -847,12 +1008,126 @@ mod storage_tests { expected_store_token: store.management_snapshot().store_token, operation: PolicyReplacementOperation::Update, conflict_handling: PolicyConflictHandling::Reject, - warnings_acknowledged: false, draft: raw, validation_receipt: validation.validation_receipt.expect("valid receipt"), } } + fn recording_audit() -> (crate::audit::WriteAudit, Arc) { + let sid = + Sid::from_well_known(::windows::Win32::Security::WinLocalSystemSid, None).expect("resolve SYSTEM SID"); + crate::audit::tests::begin(&sid, Path::new(r"C:\client.exe"), Path::new(r"C:\policy.json")) + } + + #[tokio::test] + async fn audited_old_validator_receipt_fails_once_without_publication() { + let store = PolicyStore::load_with_storage( + Some(PathBuf::from(r"C:\policy.json")), + Arc::new(TestStorage::new(Some(policy("current", 1)))), + Monitoring::Available, + ); + let mut request = update_request(&store); + let validation = store.validate_draft(&request.draft); + let canonical = validation.canonical_draft.as_ref().expect("canonical draft"); + request.validation_receipt = + store + .receipt_key + .issue("now-package-broker-policy-validator/8", canonical, &validation.findings); + let (audit, recorder) = recording_audit(); + + let error = store + .replace(request, audit) + .await + .expect_err("old validator receipt is rejected"); + + assert_eq!(error.code, ErrorCode::ValidationFailed); + assert_eq!(store.active_policy().expect("unchanged policy").metadata.revision, 1); + assert_eq!( + recorder + .events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [ + Some(agent_sysevent_codes::POLICY_WRITE_ATTEMPTED), + Some(agent_sysevent_codes::POLICY_CHANGE_FAILED) + ] + ); + assert!( + recorder.events()[1] + .fields + .iter() + .any(|(name, value)| name == "reason" && value == "invalid_receipt") + ); + } + + #[tokio::test(flavor = "current_thread")] + async fn canonical_external_observations_are_audited_once_per_change() { + let storage = Arc::new(TestStorage::new(Some(policy("current", 1)))); + let store = PolicyStore::load_with_storage( + Some(PathBuf::from(r"C:\policy.json")), + Arc::clone(&storage) as Arc, + Monitoring::Available, + ); + crate::audit::tests::take_events(); + + store.reload_from_disk(ReloadCause::ExternalChange).await; + assert!( + crate::audit::tests::take_events().is_empty(), + "unchanged policy is not an event" + ); + + storage.set_disk_state(None, true, 2); + let rejected = store.reload_from_disk(ReloadCause::ExternalChange).await; + assert_eq!(rejected.state, PolicyManagementState::Invalid); + assert!( + store.active_policy().is_none(), + "invalid external policy is not published" + ); + let events = crate::audit::tests::take_events(); + assert_eq!(events.len(), 1); + assert_eq!( + events[0].event_code, + Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_REJECTED) + ); + assert!( + events[0] + .fields + .iter() + .any(|(name, value)| name == "reason" && value == "invalid") + ); + + store.reload_from_disk(ReloadCause::ExternalChange).await; + assert!( + crate::audit::tests::take_events().is_empty(), + "unchanged invalid policy is not an event" + ); + + storage.set_disk_state(Some(policy("external", 7)), false, 3); + let applied = store.reload_from_disk(ReloadCause::ExternalChange).await; + assert_eq!(applied.state, PolicyManagementState::Active); + assert_eq!( + store + .active_policy() + .expect("external policy is active") + .metadata + .revision, + 7 + ); + let events = crate::audit::tests::take_events(); + assert_eq!(events.len(), 1); + assert_eq!( + events[0].event_code, + Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_APPLIED) + ); + + store.reload_from_disk(ReloadCause::ExternalChange).await; + assert!( + crate::audit::tests::take_events().is_empty(), + "unchanged external policy is not an event" + ); + } + #[tokio::test] async fn compatible_format_version_is_bound_to_receipts_and_persisted_tokens() { let storage = Arc::new(TestStorage::new(Some(policy("current", 1)))); @@ -864,7 +1139,7 @@ mod storage_tests { let mut request = update_request(&store); request.draft["PolicyFormatVersion"] = serde_json::json!("1.7.3"); let error = store - .replace(request.clone()) + .replace_for_tests(request.clone()) .await .expect_err("format version is receipt-bound"); assert_eq!(error.code, ErrorCode::ValidationFailed); @@ -878,14 +1153,17 @@ mod storage_tests { .issue("now-package-broker-policy-validator/8", canonical, &validation.findings); request.validation_receipt = old_receipt; let error = store - .replace(request.clone()) + .replace_for_tests(request.clone()) .await .expect_err("old validator receipt is rejected"); assert_eq!(error.code, ErrorCode::ValidationFailed); request.validation_receipt = validation.validation_receipt.expect("current receipt"); let before = store.management_snapshot().store_token; - let result = store.replace(request).await.expect("compatible format is writable"); + let result = store + .replace_for_tests(request) + .await + .expect("compatible format is writable"); assert_eq!( serde_json::to_value(&result.policy).expect("serialize committed policy")["PolicyFormatVersion"], "1.7.3" @@ -900,8 +1178,9 @@ mod storage_tests { ); } - #[tokio::test] + #[tokio::test(flavor = "current_thread")] async fn concurrent_external_replacement_is_preserved_and_published() { + crate::audit::tests::take_events(); let storage = Arc::new(TestStorage::new(Some(policy("current", 1)))); let store = PolicyStore::load_with_storage( Some(PathBuf::from(r"C:\policy.json")), @@ -909,9 +1188,13 @@ mod storage_tests { Monitoring::Available, ); let request = update_request(&store); + let (audit, recorder) = recording_audit(); storage.race_before_next_persist(policy("external", 7)); - let error = store.replace(request).await.expect_err("external replacement wins"); + let error = store + .replace(request, audit) + .await + .expect_err("external replacement wins"); assert_eq!(error.code, ErrorCode::StalePolicyStoreToken); assert_eq!( @@ -926,6 +1209,208 @@ mod storage_tests { .revision, 7 ); + assert_eq!( + crate::audit::tests::take_events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_APPLIED)] + ); + assert_eq!( + recorder + .events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [ + Some(agent_sysevent_codes::POLICY_WRITE_ATTEMPTED), + Some(agent_sysevent_codes::POLICY_CHANGE_FAILED) + ] + ); + assert!( + recorder.events()[1] + .fields + .iter() + .any(|(name, value)| name == "outcome" && value == "stale_conflict") + ); + } + + #[tokio::test(flavor = "current_thread")] + async fn post_publication_failure_is_not_audited_as_an_external_change() { + crate::audit::tests::take_events(); + let storage = Arc::new(TestStorage::new(Some(policy("current", 1)))); + let store = PolicyStore::load_with_storage( + Some(PathBuf::from(r"C:\policy.json")), + Arc::clone(&storage) as Arc, + Monitoring::Available, + ); + let request = update_request(&store); + let (audit, recorder) = recording_audit(); + storage.fail_after_next_publication(); + + let error = store + .replace(request, audit) + .await + .expect_err("authoritative reload fails"); + + assert_eq!(error.code, ErrorCode::PolicyActivationFailed); + // This request published its own content, so the reobserved difference is not an external change. + assert!(crate::audit::tests::take_events().is_empty()); + assert_eq!( + recorder + .events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [ + Some(agent_sysevent_codes::POLICY_WRITE_ATTEMPTED), + Some(agent_sysevent_codes::POLICY_CHANGE_FAILED) + ] + ); + assert!( + recorder.events()[1] + .fields + .iter() + .any(|(name, value)| name == "reason" && value == "activation_failed") + ); + assert_eq!( + store + .active_policy() + .expect("published policy is active") + .metadata + .revision, + 2 + ); + assert_eq!( + error.management.expect("management snapshot").state, + PolicyManagementState::Active + ); + } + + #[tokio::test(flavor = "current_thread")] + async fn post_publication_external_replacement_is_audited() { + crate::audit::tests::take_events(); + let storage = Arc::new(TestStorage::new(Some(policy("current", 1)))); + let store = PolicyStore::load_with_storage( + Some(PathBuf::from(r"C:\policy.json")), + Arc::clone(&storage) as Arc, + Monitoring::Available, + ); + let request = update_request(&store); + let (audit, recorder) = recording_audit(); + storage.race_after_next_publication(test_observation(Some(policy("external", 7)), false, 9)); + + let error = store + .replace(request, audit) + .await + .expect_err("the reload observed a replacement"); + + assert_eq!(error.code, ErrorCode::PolicyActivationFailed); + // The storage no longer holds the committed document, so the replacement is an external + // change: it must be audited and served, not absorbed into this request. + let active = store.active_policy().expect("external policy is active"); + assert_eq!(active.metadata.id.0, "external"); + assert_eq!(active.metadata.revision, 7); + assert_eq!( + crate::audit::tests::take_events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_APPLIED)] + ); + assert_eq!( + recorder + .events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [ + Some(agent_sysevent_codes::POLICY_WRITE_ATTEMPTED), + Some(agent_sysevent_codes::POLICY_CHANGE_FAILED) + ] + ); + assert!( + recorder.events()[1] + .fields + .iter() + .any(|(name, value)| name == "reason" && value == "activation_failed") + ); + } + + #[tokio::test(flavor = "current_thread")] + async fn post_publication_external_removal_is_audited() { + crate::audit::tests::take_events(); + let storage = Arc::new(TestStorage::new(Some(policy("current", 1)))); + let store = PolicyStore::load_with_storage( + Some(PathBuf::from(r"C:\policy.json")), + Arc::clone(&storage) as Arc, + Monitoring::Available, + ); + let request = update_request(&store); + let (audit, recorder) = recording_audit(); + storage.race_after_next_publication(test_observation(None, false, 9)); + + let error = store + .replace(request, audit) + .await + .expect_err("the reload observed a removal"); + + assert_eq!(error.code, ErrorCode::PolicyActivationFailed); + assert!( + store.active_policy().is_none(), + "a removed external policy is not published" + ); + let events = crate::audit::tests::take_events(); + assert_eq!(events.len(), 1); + assert_eq!( + events[0].event_code, + Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_REJECTED) + ); + assert!( + events[0] + .fields + .iter() + .any(|(name, value)| name == "reason" && value == "missing") + ); + assert_eq!( + recorder + .events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [ + Some(agent_sysevent_codes::POLICY_WRITE_ATTEMPTED), + Some(agent_sysevent_codes::POLICY_CHANGE_FAILED) + ] + ); + } + + #[tokio::test] + async fn audited_replacement_records_one_success_after_activation() { + let store = PolicyStore::load_with_storage( + Some(PathBuf::from(r"C:\policy.json")), + Arc::new(TestStorage::new(Some(policy("current", 1)))), + Monitoring::Available, + ); + let (audit, recorder) = recording_audit(); + + let success = store + .replace(update_request(&store), audit) + .await + .expect("replacement succeeds"); + + assert_eq!(success.policy.metadata.revision, 2); + assert_eq!( + recorder + .events() + .iter() + .map(|entry| entry.event_code) + .collect::>(), + [ + Some(agent_sysevent_codes::POLICY_WRITE_ATTEMPTED), + Some(agent_sysevent_codes::POLICY_CHANGE_SUCCEEDED) + ] + ); } #[tokio::test] @@ -942,7 +1427,10 @@ mod storage_tests { .fail_concurrent_check .store(true, std::sync::atomic::Ordering::SeqCst); - let error = store.replace(request).await.expect_err("identity check fails"); + let error = store + .replace_for_tests(request) + .await + .expect_err("identity check fails"); assert_eq!(error.code, ErrorCode::PolicyPersistenceFailed); assert_eq!(store.management_snapshot().store_token, previous_token); @@ -970,7 +1458,10 @@ mod storage_tests { .fail_target_retention .store(true, std::sync::atomic::Ordering::SeqCst); - let error = store.replace(request).await.expect_err("target retention fails"); + let error = store + .replace_for_tests(request) + .await + .expect_err("target retention fails"); assert_eq!(error.code, ErrorCode::PolicyPersistenceFailed); assert_eq!(store.management_snapshot().store_token, previous_token); @@ -996,7 +1487,10 @@ mod storage_tests { *storage.post_persist_capability.lock() = Some((PolicyWriteCapability::ReadOnly, Some(PolicyReadOnlyReason::UnsafePath))); - let success = store.replace(request).await.expect("policy replacement succeeds"); + let success = store + .replace_for_tests(request) + .await + .expect("policy replacement succeeds"); assert_eq!(success.management.write_capability, PolicyWriteCapability::ReadOnly); assert_eq!( @@ -1022,7 +1516,10 @@ mod storage_tests { ); assert_eq!(store.watched_path(), canonical); - let success = store.replace(update_request(&store)).await.expect("replace policy"); + let success = store + .replace_for_tests(update_request(&store)) + .await + .expect("replace policy"); assert_eq!(&*storage.persisted_configured_paths.lock(), &[configured]); assert_eq!(store.watched_path(), canonical); diff --git a/crates/now-package-broker/src/policy_store/receipt.rs b/crates/now-package-broker/src/policy_store/receipt.rs index 4aec0b184..7f402aa75 100644 --- a/crates/now-package-broker/src/policy_store/receipt.rs +++ b/crates/now-package-broker/src/policy_store/receipt.rs @@ -115,7 +115,6 @@ mod tests { expected_store_token: store.management_snapshot().store_token, operation, conflict_handling: PolicyConflictHandling::Reject, - warnings_acknowledged: false, draft: raw, validation_receipt: validation.validation_receipt.expect("valid receipt"), } @@ -199,7 +198,10 @@ mod tests { let mut stale_request = request(&store, PolicyReplacementOperation::Update, raw.clone()); storage.set_disk_state(Some(policy("retargeted", 9)), false, 9); stale_request.conflict_handling = PolicyConflictHandling::ConfirmOverwrite; - let stale_error = store.replace(stale_request).await.expect_err("stale token rejected"); + let stale_error = store + .replace_for_tests(stale_request) + .await + .expect_err("stale token rejected"); assert_eq!(stale_error.code, ErrorCode::StalePolicyStoreToken); assert!(stale_error.management.is_some()); assert_eq!( @@ -208,11 +210,14 @@ mod tests { ); let mut tampered = request(&store, PolicyReplacementOperation::Update, raw); tampered.draft["Metadata"]["Publisher"] = "Tampered".into(); - let receipt_error = store.replace(tampered).await.expect_err("tampered draft rejected"); + let receipt_error = store + .replace_for_tests(tampered) + .await + .expect_err("tampered draft rejected"); assert_eq!(receipt_error.code, ErrorCode::ValidationFailed); } #[tokio::test] - async fn store_requires_warning_acknowledgement() { + async fn store_saves_valid_drafts_with_advisory_findings() { let store = PolicyStore::for_tests(None); let mut risky = serde_json::to_value(draft("risky")).expect("serialize draft"); risky["Rules"] = serde_json::Value::Array( @@ -251,14 +256,11 @@ mod tests { serde_json::to_value(round_trip).expect("serialize round-tripped validation result"), serialized ); - let mut replacement = request(&store, PolicyReplacementOperation::Create, risky); - let error = store - .replace(replacement.clone()) + let replacement = request(&store, PolicyReplacementOperation::Create, risky); + store + .replace_for_tests(replacement) .await - .expect_err("warning must be acknowledged"); - assert_eq!(error.code, ErrorCode::WarningConfirmationRequired); - replacement.warnings_acknowledged = true; - store.replace(replacement).await.expect("acknowledged warning succeeds"); + .expect("advisory findings do not block a valid draft"); } #[tokio::test] async fn canonical_sensitive_warnings_accept_the_original_receipt() { @@ -309,7 +311,6 @@ mod tests { expected_store_token: store.management_snapshot().store_token, operation: PolicyReplacementOperation::Create, conflict_handling: PolicyConflictHandling::Reject, - warnings_acknowledged: true, draft: canonical.clone(), validation_receipt: receipt.clone(), }; @@ -317,13 +318,13 @@ mod tests { let mut changed = replacement.clone(); changed.draft["Rules"][0]["Constraints"]["AllowSkipHashCheck"] = serde_json::json!(false); let error = store - .replace(changed) + .replace_for_tests(changed) .await .expect_err("meaningful option change invalidates receipt"); assert_eq!(error.code, ErrorCode::ValidationFailed); } store - .replace(replacement) + .replace_for_tests(replacement) .await .unwrap_or_else(|error| panic!("{option} via {explicit} failed: {error:?}")); } @@ -334,21 +335,21 @@ mod tests { let create = PolicyStore::for_tests(None); let raw = serde_json::to_value(draft("created")).expect("serialize draft"); let created = create - .replace(request(&create, PolicyReplacementOperation::Create, raw)) + .replace_for_tests(request(&create, PolicyReplacementOperation::Create, raw)) .await .expect("create succeeds"); assert_eq!(created.policy.metadata.revision, 1); let update = PolicyStore::for_tests(Some(policy("current", 7))); let raw = serde_json::to_value(draft("current")).expect("serialize draft"); let updated = update - .replace(request(&update, PolicyReplacementOperation::Update, raw)) + .replace_for_tests(request(&update, PolicyReplacementOperation::Update, raw)) .await .expect("update succeeds"); assert_eq!(updated.policy.metadata.revision, 8); let replace = PolicyStore::for_tests(Some(policy("current", 7))); let raw = serde_json::to_value(draft("replacement")).expect("serialize draft"); let replaced = replace - .replace(request(&replace, PolicyReplacementOperation::ReplaceIdentity, raw)) + .replace_for_tests(request(&replace, PolicyReplacementOperation::ReplaceIdentity, raw)) .await .expect("identity replacement succeeds"); assert_eq!(replaced.policy.metadata.revision, 1); @@ -360,14 +361,14 @@ mod tests { ); let raw = serde_json::to_value(draft("repaired")).expect("serialize draft"); let repaired = repair - .replace(request(&repair, PolicyReplacementOperation::Repair, raw)) + .replace_for_tests(request(&repair, PolicyReplacementOperation::Repair, raw)) .await .expect("repair succeeds"); assert_eq!(repaired.policy.metadata.revision, 1); let wrong_identity = PolicyStore::for_tests(Some(policy("current", 1))); let raw = serde_json::to_value(draft("different")).expect("serialize draft"); let error = wrong_identity - .replace(request(&wrong_identity, PolicyReplacementOperation::Update, raw)) + .replace_for_tests(request(&wrong_identity, PolicyReplacementOperation::Update, raw)) .await .expect_err("update must preserve identity"); assert_eq!(error.code, ErrorCode::Conflict); @@ -377,7 +378,7 @@ mod tests { let store = PolicyStore::for_tests(Some(policy("current", 1))); let raw = serde_json::to_value(draft("current")).expect("serialize draft"); let first = request(&store, PolicyReplacementOperation::Update, raw); - let (first, second) = tokio::join!(store.replace(first.clone()), store.replace(first)); + let (first, second) = tokio::join!(store.replace_for_tests(first.clone()), store.replace_for_tests(first)); let outcomes = [first, second]; assert_eq!(outcomes.iter().filter(|result| result.is_ok()).count(), 1); assert_eq!( @@ -399,7 +400,7 @@ mod tests { storage.fail_persist.store(true, std::sync::atomic::Ordering::SeqCst); let raw = serde_json::to_value(draft("current")).expect("serialize draft"); let error = store - .replace(request(&store, PolicyReplacementOperation::Update, raw)) + .replace_for_tests(request(&store, PolicyReplacementOperation::Update, raw)) .await .expect_err("persistence failure"); assert_eq!(error.code, ErrorCode::PolicyPersistenceFailed); @@ -411,12 +412,27 @@ mod tests { assert_ne!(management.store_token, old_token); assert!(store.active_policy().is_none()); } - #[tokio::test] + #[tokio::test(flavor = "current_thread")] async fn readiness_reloads_each_disk_state_after_provisional_load() { - for (disk_policy, invalid, expected) in [ - (Some(policy("changed", 2)), false, PolicyManagementState::Active), - (None, false, PolicyManagementState::Missing), - (None, true, PolicyManagementState::Invalid), + for (disk_policy, invalid, expected, expected_event) in [ + ( + Some(policy("changed", 2)), + false, + PolicyManagementState::Active, + Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_APPLIED), + ), + ( + None, + false, + PolicyManagementState::Missing, + Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_REJECTED), + ), + ( + None, + true, + PolicyManagementState::Invalid, + Some(agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_REJECTED), + ), ] { let storage = Arc::new(TestStorage::new(Some(policy("provisional", 1)))); let store = PolicyStore::load_with_storage( @@ -425,11 +441,27 @@ mod tests { Monitoring::Initializing, ); storage.set_disk_state(disk_policy, invalid, 3); + crate::audit::tests::take_events(); assert_eq!(store.mark_monitoring_ready().await.state, expected); assert_eq!( store.active_policy().is_some(), expected == PolicyManagementState::Active ); + // A policy that changed before the watcher reported ready is an external change. + let events = crate::audit::tests::take_events(); + assert_eq!( + events.iter().map(|entry| entry.event_code).collect::>(), + [expected_event] + ); + assert_eq!( + store.mark_monitoring_ready().await.state, + expected, + "a settled store keeps its state on a second readiness report" + ); + assert!( + crate::audit::tests::take_events().is_empty(), + "readiness audits the observation once" + ); } } #[tokio::test] @@ -470,7 +502,7 @@ mod tests { ); replacement.expected_store_token = token; let error = store - .replace(replacement) + .replace_for_tests(replacement) .await .expect_err("monitoring failure blocks PUT"); assert_eq!(error.code, ErrorCode::BrokerPaused); diff --git a/crates/now-package-broker/src/server/mod.rs b/crates/now-package-broker/src/server/mod.rs index 61664d16c..6ace82de8 100644 --- a/crates/now-package-broker/src/server/mod.rs +++ b/crates/now-package-broker/src/server/mod.rs @@ -2,6 +2,7 @@ use std::collections::HashMap; use std::fmt; +use std::path::PathBuf; use std::sync::Arc; use std::time::{Duration, Instant}; @@ -48,6 +49,7 @@ use responses::{ // The unit value marks the scope in which an authenticated policy management request is dispatched. tokio::task_local! { static POLICY_MANAGEMENT_AUTHENTICATED: (); + static POLICY_WRITE_AUDIT: crate::audit::WriteAudit; } /// How long a per-user manager availability probe stays fresh before it is re-run. @@ -293,6 +295,10 @@ async fn authenticate_policy_management( request: Request, next: Next, ) -> Response { + let write_audit = matches!((request.method(), request.uri().path()), (&Method::PUT, "/v1/policy")).then(|| { + let configured_path = PathBuf::from(state.policy_store.management_snapshot().configured_path); + crate::audit::WriteAudit::begin(client.user_sid(), client.executable_path(), &configured_path) + }); let protected = matches!( (request.method(), request.uri().path()), (&Method::GET, "/v1/policy/management") @@ -302,6 +308,9 @@ async fn authenticate_policy_management( ); if protected { if let Err(error) = client.validate_connection(state.skip_signature_validation) { + if let Some(audit) = write_audit { + audit.denied(crate::audit::DenialReason::AuthenticationFailed); + } warn!(error = format!("{error:#}"), "Rejected policy management request"); return ( StatusCode::UNAUTHORIZED, @@ -312,7 +321,12 @@ async fn authenticate_policy_management( ) .into_response(); } - return POLICY_MANAGEMENT_AUTHENTICATED.scope((), next.run(request)).await; + let authenticated = POLICY_MANAGEMENT_AUTHENTICATED.scope((), next.run(request)); + return if let Some(audit) = write_audit { + POLICY_WRITE_AUDIT.scope(audit, authenticated).await + } else { + authenticated.await + }; } next.run(request).await } @@ -381,7 +395,11 @@ impl PackageBrokerServer for BrokerConnection { request: PolicyReplacementRequest, ) -> Result { require_policy_management_authentication()?; + let audit = POLICY_WRITE_AUDIT + .try_with(Clone::clone) + .map_err(|_| error_response(ErrorCode::InternalError, "policy write audit context is unavailable"))?; if !self.client.is_elevated_administrator() { + audit.denied(crate::audit::DenialReason::AdministratorRequired); return Err(error_response( ErrorCode::AdministratorRequired, "policy replacement requires an elevated Administrator", @@ -389,7 +407,7 @@ impl PackageBrokerServer for BrokerConnection { } self.state .policy_store - .replace(request) + .replace(request, audit) .await .map(|success| PolicyReplacementResponse { response_kind: now_policy_api::PolicyReplacementResponseKind, @@ -1009,7 +1027,6 @@ mod tests { "ExpectedStoreToken": replacement_state.policy_store.management_snapshot().store_token, "Operation": "Create", "ConflictHandling": "Reject", - "WarningsAcknowledged": false, "Draft": replacement_draft, "ValidationReceipt": validation.validation_receipt.expect("valid receipt"), }); @@ -1036,7 +1053,7 @@ mod tests { Method::PUT, "/v1/policy", "Application/JSON; charset=utf-8", - r#"{"RequestKind":"PolicyReplacementRequest","RequestVersion":"1.0","ExpectedStoreToken":"invalid","Operation":"Create","ConflictHandling":"Reject","WarningsAcknowledged":false,"ValidationReceipt":"invalid","Draft":{"PolicyFormatVersion":"1.0.0","Metadata":{"Id":"created","Publisher":"Test","Publisher":"Test"},"Enforcement":{"DefaultDecision":"Deny"},"Rules":[]}}"#, + r#"{"RequestKind":"PolicyReplacementRequest","RequestVersion":"1.0","ExpectedStoreToken":"invalid","Operation":"Create","ConflictHandling":"Reject","ValidationReceipt":"invalid","Draft":{"PolicyFormatVersion":"1.0.0","Metadata":{"Id":"created","Publisher":"Test","Publisher":"Test"},"Enforcement":{"DefaultDecision":"Deny"},"Rules":[]}}"#, ), ] { let response = route_raw( @@ -1211,7 +1228,6 @@ mod tests { "ExpectedStoreToken": state.policy_store.management_snapshot().store_token, "Operation": "Create", "ConflictHandling": "Reject", - "WarningsAcknowledged": false, "Draft": draft, "ValidationReceipt": validation.validation_receipt.expect("valid receipt") }); diff --git a/crates/now-package-broker/src/task.rs b/crates/now-package-broker/src/task.rs index fdeb01fc7..dec73e04a 100644 --- a/crates/now-package-broker/src/task.rs +++ b/crates/now-package-broker/src/task.rs @@ -84,7 +84,7 @@ impl Task for BrokerTask { Ok(Err(failure)) => fail_closed(&state.policy_store, failure).await, Err(_) => fail_closed(&state.policy_store, WatcherFailure::TaskTerminated).await, } - tokio::spawn(monitor_watcher_task( + let monitor_handle = tokio::spawn(monitor_watcher_task( Arc::clone(&state.policy_store), shutdown.clone(), watcher_handle, @@ -102,11 +102,17 @@ impl Task for BrokerTask { info!("package broker received shutdown signal"); shutdown.cancel(); - // Wait for the server task to finish. - match server_handle.await { + // Wait for the writers of policy audit events to stop, so the drain below is complete. The + // pipe server reports a connection it gave up on by keeping an audit lease alive, so the + // queue is flushed rather than closed and its terminal event is not rejected. + let result = match server_handle.await { Ok(Ok(())) => Ok(()), Ok(Err(error)) => Err(error).context("broker pipe server error"), Err(error) => Err(error).context("broker server task panicked"), - } + }; + let _ = monitor_handle.await; + crate::audit::drain(); + + result } } diff --git a/crates/sysevent-codes/src/lib.rs b/crates/sysevent-codes/src/lib.rs index e2eaad987..d404b3f6c 100644 --- a/crates/sysevent-codes/src/lib.rs +++ b/crates/sysevent-codes/src/lib.rs @@ -320,54 +320,6 @@ pub fn auth_summary( .field("by_reason", by_reason_json) } -// 6000-6099 **Agent Integration** - -/// `DevolutionsSession.exe` started in session; include session id & kind (console/remote). -pub const USER_SESSION_PROCESS_STARTED: u32 = 6000; -/// Exit code; who triggered. -pub const USER_SESSION_PROCESS_TERMINATED: u32 = 6001; -pub const UPDATER_TASK_ENABLED: u32 = 6010; -pub const UPDATER_ERROR: u32 = 6011; -pub const PEDM_ENABLED: u32 = 6020; - -pub fn user_session_process_started(session_id: u32, kind: impl ToString, exe: impl ToString) -> Entry { - Entry::new("User session process started") - .event_code(USER_SESSION_PROCESS_STARTED) - .severity(Severity::Info) - .field("session_id", session_id) - .field("kind", kind) // "console","remote" - .field("exe", exe) -} - -pub fn user_session_process_terminated(session_id: u32, exit_code: i32, by: impl ToString) -> Entry { - Entry::new("User session process terminated") - .event_code(USER_SESSION_PROCESS_TERMINATED) - .severity(Severity::Info) - .field("session_id", session_id) - .field("exit_code", exit_code) - .field("by", by) // "user","service","timeout" -} - -pub fn updater_task_enabled() -> Entry { - Entry::new("Updater task enabled") - .event_code(UPDATER_TASK_ENABLED) - .severity(Severity::Info) -} - -pub fn updater_error(step: impl ToString, error: impl std::fmt::Display) -> Entry { - Entry::new("Updater error") - .event_code(UPDATER_ERROR) - .severity(Severity::Error) - .field("step", step) // "download","verify","apply","rollback" - .field("error_chain", format!("{error:#}")) -} - -pub fn pedm_enabled() -> Entry { - Entry::new("PEDM enabled") - .event_code(PEDM_ENABLED) - .severity(Severity::Info) -} - // 7000-7099 **Health** pub const RECORDING_STORAGE_LOW: u32 = 7010; // (Warning): remaining_bytes, threshold_bytes @@ -399,3 +351,41 @@ pub fn xmf_not_found(path: impl AsRef, error: impl std::fmt::Display) -> E .field("path", path.as_ref().display()) .field("error_chain", format!("{error:#}")) } + +/// Every declared Gateway event code, paired with its symbolic name. +/// +/// `devolutions-gateway.mc` is checked against this inventory, and the check is an exact match in +/// both directions, so adding a code here means adding its messages to the catalog, and an +/// Agent-only code must never appear there. +pub static DECLARED_CODES: &[(&str, u32)] = &[ + ("SERVICE_STARTED", SERVICE_STARTED), + ("SERVICE_STOPPING", SERVICE_STOPPING), + ("CONFIG_INVALID", CONFIG_INVALID), + ("START_FAILED", START_FAILED), + ("BOOT_STACKTRACE_WRITTEN", BOOT_STACKTRACE_WRITTEN), + ("LISTENER_STARTED", LISTENER_STARTED), + ("LISTENER_BIND_FAILED", LISTENER_BIND_FAILED), + ("LISTENER_STOPPED", LISTENER_STOPPED), + ("TLS_CONFIGURED", TLS_CONFIGURED), + ("TLS_VERIFY_STRICT_DISABLED", TLS_VERIFY_STRICT_DISABLED), + ("TLS_CERTIFICATE_REJECTED", TLS_CERTIFICATE_REJECTED), + ("SYSTEM_CERT_SELECTED", SYSTEM_CERT_SELECTED), + ("TLS_KEY_LOAD_FAILED", TLS_KEY_LOAD_FAILED), + ("TLS_CERTIFICATE_NAME_MISMATCH", TLS_CERTIFICATE_NAME_MISMATCH), + ("TLS_NO_SUITABLE_CERTIFICATE", TLS_NO_SUITABLE_CERTIFICATE), + ("SESSION_OPENED", SESSION_OPENED), + ("SESSION_CLOSED", SESSION_CLOSED), + ("TOKEN_PROVISIONED", TOKEN_PROVISIONED), + ("TOKEN_REUSED", TOKEN_REUSED), + ("TOKEN_REUSE_LIMIT_EXCEEDED", TOKEN_REUSE_LIMIT_EXCEEDED), + ("RECORDING_STARTED", RECORDING_STARTED), + ("RECORDING_STOPPED", RECORDING_STOPPED), + ("RECORDING_ERROR", RECORDING_ERROR), + ("JWT_REJECTED", JWT_REJECTED), + ("JWT_ANOMALY", JWT_ANOMALY), + ("AUTHORIZATION_DENIED", AUTHORIZATION_DENIED), + ("AUTH_SUMMARY", AUTH_SUMMARY), + ("RECORDING_STORAGE_LOW", RECORDING_STORAGE_LOW), + ("DEBUG_OPTIONS_ENABLED", DEBUG_OPTIONS_ENABLED), + ("XMF_NOT_FOUND", XMF_NOT_FOUND), +]; diff --git a/devolutions-agent/build.rs b/devolutions-agent/build.rs index b8d9ad669..1a4ef4eec 100644 --- a/devolutions-agent/build.rs +++ b/devolutions-agent/build.rs @@ -3,6 +3,9 @@ fn main() { #[cfg(target_os = "windows")] win::embed_version_rc(); + + #[cfg(target_os = "windows")] + win::embed_devolutions_agent_mc(); } fn generate_psu_agent_proto() { @@ -100,4 +103,84 @@ END"#, version_rc } + + pub(super) fn embed_devolutions_agent_mc() { + use std::path::PathBuf; + use std::process::Command; + + // Cargo only ever reports "release" or "debug" here: every profile inheriting the release + // profile (release, production, profiling) reports "release". No profile overrides + // `debug-assertions`, so this selects exactly the builds where the runtime uses the Windows + // Event Log sink (`not(debug_assertions)`), and those builds need the embedded catalog. + let profile = env::var("PROFILE").unwrap_or_default(); + if profile != "release" { + return; + } + + let mc_exe = find_mc().unwrap_or_else(|| { + panic!( + "mc.exe is required to embed the Devolutions Agent Event Log catalog; \ + use a Visual Studio developer shell or set WindowsSdkVerBinPath or WindowsSdkDir" + ) + }); + let manifest_dir = PathBuf::from(env::var("CARGO_MANIFEST_DIR").expect("CARGO_MANIFEST_DIR")); + let catalog = manifest_dir.join("devolutions-agent.mc"); + println!("cargo:rerun-if-changed={}", catalog.display()); + + let out_dir = PathBuf::from(env::var("OUT_DIR").expect("OUT_DIR")); + let status = Command::new(mc_exe) + .current_dir(&out_dir) + .args(["-um", "-h", ".", "-r", "."]) + .arg(catalog.canonicalize().expect("canonicalize Agent message catalog")) + .status() + .expect("run mc.exe"); + assert!(status.success(), "mc.exe failed with status {status}"); + + let resource = out_dir.join("devolutions-agent.rc"); + assert!(resource.is_file(), "mc.exe did not generate {}", resource.display()); + embed_resource::compile(resource, embed_resource::NONE) + .manifest_required() + .expect("BUG: failed to embed devolutions-agent.rc"); + } + + fn find_mc() -> Option { + if let Ok(sdk_bin) = env::var("WindowsSdkVerBinPath") { + let sdk_bin = std::path::Path::new(&sdk_bin); + for candidate in [sdk_bin.join("mc.exe"), sdk_bin.join("x64").join("mc.exe")] { + if candidate.is_file() { + return Some(candidate); + } + } + } + + let bin_dir = std::path::PathBuf::from(env::var_os("WindowsSdkDir")?).join("bin"); + let direct = bin_dir.join("x64").join("mc.exe"); + if direct.is_file() { + return Some(direct); + } + + let mut versions: Vec<_> = fs::read_dir(bin_dir) + .ok()? + .filter_map(Result::ok) + .map(|entry| entry.path()) + .filter(|path| path.is_dir()) + .collect(); + versions.sort_by_key(|path| { + std::cmp::Reverse( + path.file_name() + .and_then(|name| name.to_str()) + .and_then(|name| { + name.split('.') + .map(str::parse::) + .collect::, _>>() + .ok() + }) + .unwrap_or_default(), + ) + }); + versions + .into_iter() + .map(|directory| directory.join("x64").join("mc.exe")) + .find(|path| path.is_file()) + } } diff --git a/devolutions-agent/devolutions-agent.mc b/devolutions-agent/devolutions-agent.mc new file mode 100644 index 000000000..0edd300bd --- /dev/null +++ b/devolutions-agent/devolutions-agent.mc @@ -0,0 +1,250 @@ +; Devolutions Agent Windows Event Log message definitions. +; Scope: the codes declared in the `agent-sysevent-codes` crate, and only those. +; Codes shared with Devolutions Gateway are duplicated here, so the Agent never refers to a +; message it does not carry, and Gateway-only translations are absent. +; Languages: English, French, German. + +MessageIdTypedef=DWORD + +SeverityNames=( + Success=0x0:STATUS_SEVERITY_SUCCESS + Informational=0x1:STATUS_SEVERITY_INFORMATIONAL + Warning=0x2:STATUS_SEVERITY_WARNING + Error=0x3:STATUS_SEVERITY_ERROR +) + +FacilityNames=( + Application=0x0:FACILITY_APPLICATION +) + +LanguageNames=( + English=0x409:MSG00409 + French=0x40c:MSG0040c + German=0x407:MSG00407 +) + +; 1000-1099 Service / Lifecycle + +MessageId=1000 +SymbolicName=SERVICE_STARTED +Language=English +Service started. Context=%1 Version=%2 +. +Language=French +Service démarré. Contexte=%1 Version=%2 +. +Language=German +Dienst gestartet. Kontext=%1 Version=%2 +. + +MessageId=1001 +SymbolicName=SERVICE_STOPPING +Language=English +Service stopping. Context=%1 Reason=%2 +. +Language=French +Arrêt du service. Contexte=%1 Raison=%2 +. +Language=German +Dienst wird gestoppt. Kontext=%1 Grund=%2 +. + +MessageId=1010 +SymbolicName=CONFIG_INVALID +Language=English +Configuration invalid. Context=%1 Path=%2 Error=%3 Reason=%4 +. +Language=French +Configuration invalide. Contexte=%1 Chemin=%2 Erreur=%3 Raison=%4 +. +Language=German +Ungültige Konfiguration. Kontext=%1 Pfad=%2 Fehler=%3 Grund=%4 +. + +MessageId=1020 +SymbolicName=START_FAILED +Language=English +Start failed. Context=%1 Cause=%2 Error=%3 +. +Language=French +Échec du démarrage. Contexte=%1 Cause=%2 Erreur=%3 +. +Language=German +Start fehlgeschlagen. Kontext=%1 Ursache=%2 Fehler=%3 +. + +MessageId=1030 +SymbolicName=BOOT_STACKTRACE_WRITTEN +Language=English +Boot stacktrace written. Context=%1 Path=%2 +. +Language=French +Trace d’amorçage écrite. Contexte=%1 Chemin=%2 +. +Language=German +Boot-Stacktrace geschrieben. Kontext=%1 Pfad=%2 +. + +; 6000-6099 User Sessions + +MessageId=6000 +SymbolicName=USER_SESSION_PROCESS_STARTED +Language=English +User session process started. Context=%1 SessionId=%2 Kind=%3 Exe=%4 +. +Language=French +Processus de session utilisateur démarré. Contexte=%1 SessionId=%2 Type=%3 Exe=%4 +. +Language=German +Benutzersitzungsprozess gestartet. Kontext=%1 SessionId=%2 Typ=%3 Exe=%4 +. + +MessageId=6001 +SymbolicName=USER_SESSION_PROCESS_TERMINATED +Language=English +User session process terminated. Context=%1 SessionId=%2 ExitCode=%3 By=%4 +. +Language=French +Processus de session utilisateur terminé. Contexte=%1 SessionId=%2 CodeSortie=%3 Par=%4 +. +Language=German +Benutzersitzungsprozess beendet. Kontext=%1 SessionId=%2 ExitCode=%3 Durch=%4 +. + +; 6100-6199 Updater + +MessageId=6100 +SymbolicName=UPDATER_TASK_ENABLED +Language=English +Updater task enabled. Context=%1 +. +Language=French +Tâche de mise à jour activée. Contexte=%1 +. +Language=German +Update-Aufgabe aktiviert. Kontext=%1 +. + +MessageId=6101 +SymbolicName=UPDATER_ERROR +Language=English +Updater error. Context=%1 Step=%2 Error=%3 +. +Language=French +Erreur de mise à jour. Contexte=%1 Étape=%2 Erreur=%3 +. +Language=German +Update-Fehler. Kontext=%1 Schritt=%2 Fehler=%3 +. + +; 6200-6299 PEDM + +MessageId=6200 +SymbolicName=PEDM_ENABLED +Language=English +PEDM enabled. Context=%1 +. +Language=French +PEDM activé. Contexte=%1 +. +Language=German +PEDM aktiviert. Kontext=%1 +. + +; 8000-8099 Package Broker / Policy Management + +MessageId=8000 +SymbolicName=POLICY_WRITE_ATTEMPTED +Language=English +Policy management write attempted. Context=%1 ActorSid=%2 ActorExe=%3 Intent=%4 Path=%5 +. +Language=French +Tentative d’écriture de politique. Contexte=%1 SidActeur=%2 ExeActeur=%3 Intention=%4 Chemin=%5 +. +Language=German +Richtlinien-Schreibvorgang versucht. Kontext=%1 AkteurSid=%2 AkteurExe=%3 Absicht=%4 Pfad=%5 +. + +MessageId=8001 +SymbolicName=POLICY_WRITE_DENIED +Language=English +Policy management write denied. Context=%1 ActorSid=%2 ActorExe=%3 Intent=%4 Path=%5 Reason=%6 +. +Language=French +Écriture de politique refusée. Contexte=%1 SidActeur=%2 ExeActeur=%3 Intention=%4 Chemin=%5 Raison=%6 +. +Language=German +Richtlinien-Schreibvorgang verweigert. Kontext=%1 AkteurSid=%2 AkteurExe=%3 Absicht=%4 Pfad=%5 Grund=%6 +. + +MessageId=8002 +SymbolicName=POLICY_CREATE_FAILED +Language=English +Policy creation failed. Context=%1 ActorSid=%2 ActorExe=%3 Intent=%4 Path=%5 Operation=%6 Outcome=%7 Reason=%8 +. +Language=French +Échec de la création de politique. Contexte=%1 SidActeur=%2 ExeActeur=%3 Intention=%4 Chemin=%5 Opération=%6 Résultat=%7 Raison=%8 +. +Language=German +Richtlinienerstellung fehlgeschlagen. Kontext=%1 AkteurSid=%2 AkteurExe=%3 Absicht=%4 Pfad=%5 Vorgang=%6 Ergebnis=%7 Grund=%8 +. + +MessageId=8003 +SymbolicName=POLICY_CREATE_SUCCEEDED +Language=English +Policy creation succeeded. Context=%1 ActorSid=%2 ActorExe=%3 Path=%4 OldId=%5 OldRevision=%6 NewId=%7 NewRevision=%8 Intent=%9 Operation=%10 Outcome=%11 +. +Language=French +Création de politique réussie. Contexte=%1 SidActeur=%2 ExeActeur=%3 Chemin=%4 AncienId=%5 AncienneRévision=%6 NouvelId=%7 NouvelleRévision=%8 Intention=%9 Opération=%10 Résultat=%11 +. +Language=German +Richtlinie erfolgreich erstellt. Kontext=%1 AkteurSid=%2 AkteurExe=%3 Pfad=%4 AlteId=%5 AlteRevision=%6 NeueId=%7 NeueRevision=%8 Absicht=%9 Vorgang=%10 Ergebnis=%11 +. + +MessageId=8004 +SymbolicName=POLICY_CHANGE_FAILED +Language=English +Policy change failed. Context=%1 ActorSid=%2 ActorExe=%3 Intent=%4 Path=%5 Operation=%6 Outcome=%7 Reason=%8 +. +Language=French +Échec de la modification de politique. Contexte=%1 SidActeur=%2 ExeActeur=%3 Intention=%4 Chemin=%5 Opération=%6 Résultat=%7 Raison=%8 +. +Language=German +Richtlinienänderung fehlgeschlagen. Kontext=%1 AkteurSid=%2 AkteurExe=%3 Absicht=%4 Pfad=%5 Vorgang=%6 Ergebnis=%7 Grund=%8 +. + +MessageId=8005 +SymbolicName=POLICY_CHANGE_SUCCEEDED +Language=English +Policy change succeeded. Context=%1 ActorSid=%2 ActorExe=%3 Path=%4 OldId=%5 OldRevision=%6 NewId=%7 NewRevision=%8 Intent=%9 Operation=%10 Outcome=%11 +. +Language=French +Modification de politique réussie. Contexte=%1 SidActeur=%2 ExeActeur=%3 Chemin=%4 AncienId=%5 AncienneRévision=%6 NouvelId=%7 NouvelleRévision=%8 Intention=%9 Opération=%10 Résultat=%11 +. +Language=German +Richtlinie erfolgreich geändert. Kontext=%1 AkteurSid=%2 AkteurExe=%3 Pfad=%4 AlteId=%5 AlteRevision=%6 NeueId=%7 NeueRevision=%8 Absicht=%9 Vorgang=%10 Ergebnis=%11 +. + +MessageId=8010 +SymbolicName=POLICY_EXTERNAL_CHANGE_APPLIED +Language=English +External policy change applied. Context=%1 Path=%2 NewId=%3 NewRevision=%4 +. +Language=French +Modification externe de la politique appliquée. Contexte=%1 Chemin=%2 NouvelId=%3 NouvelleRévision=%4 +. +Language=German +Externe Richtlinienänderung angewendet. Kontext=%1 Pfad=%2 NeueId=%3 NeueRevision=%4 +. + +MessageId=8011 +SymbolicName=POLICY_EXTERNAL_CHANGE_REJECTED +Language=English +External policy change rejected. Context=%1 Path=%2 Reason=%3 +. +Language=French +Modification externe de la politique rejetée. Contexte=%1 Chemin=%2 Raison=%3 +. +Language=German +Externe Richtlinienänderung abgelehnt. Kontext=%1 Pfad=%2 Grund=%3 +. diff --git a/devolutions-gateway/build.rs b/devolutions-gateway/build.rs index d242d5610..4522aa8c4 100644 --- a/devolutions-gateway/build.rs +++ b/devolutions-gateway/build.rs @@ -94,20 +94,22 @@ END"#, use std::path::PathBuf; use std::process::Command; - // --- gate: only release builds ------------------------------------- + // --- gate: mirror the runtime sink, `cfg(not(debug_assertions))` ---- + // Cargo only ever reports "release" or "debug" here: every profile inheriting the release + // profile (release, production, profiling) reports "release". No profile overrides + // `debug-assertions`, so this selects exactly the builds where the runtime uses the Windows + // Event Log sink, and those builds need the embedded catalog. let profile = env::var("PROFILE").unwrap_or_default(); if profile != "release" { return; } - // --- gate: ignore with a warning when mc is not found -------------- - let mc_exe_path = match find_mc() { - Some(path) => path, - None => { - println!("cargo:warning=Did not find mc.exe"); - return; - } - }; + let mc_exe_path = find_mc().unwrap_or_else(|| { + panic!( + "mc.exe is required to embed the Devolutions Gateway Event Log catalog; \ + use a Visual Studio developer shell or set WindowsSdkVerBinPath or WindowsSdkDir" + ) + }); // --- inputs/paths --------------------------------------------------- let manifest_dir = PathBuf::from(env::var("CARGO_MANIFEST_DIR").expect("CARGO_MANIFEST_DIR")); @@ -163,20 +165,42 @@ END"#, fn find_mc() -> Option { if let Ok(sdk_bin) = env::var("WindowsSdkVerBinPath") { - let p = std::path::Path::new(&sdk_bin).join("mc.exe"); - if p.exists() { - return Some(p); + let sdk_bin = std::path::Path::new(&sdk_bin); + for candidate in [sdk_bin.join("mc.exe"), sdk_bin.join("x64").join("mc.exe")] { + if candidate.is_file() { + return Some(candidate); + } } } - if let Ok(sdk_dir) = env::var("WindowsSdkDir") { - // e.g. C:\Program Files (x86)\Windows Kits\10\ - let candidate = std::path::Path::new(&sdk_dir).join("bin").join("x64").join("mc.exe"); - if candidate.exists() { - return Some(candidate); - } + let bin_dir = std::path::PathBuf::from(env::var_os("WindowsSdkDir")?).join("bin"); + let direct = bin_dir.join("x64").join("mc.exe"); + if direct.is_file() { + return Some(direct); } - None + let mut versions: Vec<_> = fs::read_dir(bin_dir) + .ok()? + .filter_map(Result::ok) + .map(|entry| entry.path()) + .filter(|path| path.is_dir()) + .collect(); + versions.sort_by_key(|path| { + std::cmp::Reverse( + path.file_name() + .and_then(|name| name.to_str()) + .and_then(|name| { + name.split('.') + .map(str::parse::) + .collect::, _>>() + .ok() + }) + .unwrap_or_default(), + ) + }); + versions + .into_iter() + .map(|directory| directory.join("x64").join("mc.exe")) + .find(|path| path.is_file()) } } diff --git a/devolutions-gateway/devolutions-gateway.mc b/devolutions-gateway/devolutions-gateway.mc index 4a9b99f8a..5c8f24038 100644 --- a/devolutions-gateway/devolutions-gateway.mc +++ b/devolutions-gateway/devolutions-gateway.mc @@ -1,4 +1,4 @@ -; ---------------------------------------------------------------------- +; ---------------------------------------------------------------------- ; Devolutions Gateway - Windows Event Log message definitions (.mc) ; English (0x409), French (0x40c), German (0x407) ; ---------------------------------------------------------------------- @@ -30,8 +30,10 @@ MessageId=1000 SymbolicName=SERVICE_STARTED Language=English Service started. Context=%1 Version=%2 +. Language=French Service démarré. Contexte=%1 Version=%2 +. Language=German Dienst gestartet. Kontext=%1 Version=%2 . @@ -40,8 +42,10 @@ MessageId=1001 SymbolicName=SERVICE_STOPPING Language=English Service stopping. Context=%1 Reason=%2 +. Language=French Arrêt du service. Contexte=%1 Raison=%2 +. Language=German Dienst wird gestoppt. Kontext=%1 Grund=%2 . @@ -50,8 +54,10 @@ MessageId=1010 SymbolicName=CONFIG_INVALID Language=English Configuration invalid. Context=%1 Path=%2 Error=%3 Reason=%4 +. Language=French Configuration invalide. Contexte=%1 Chemin=%2 Erreur=%3 Raison=%4 +. Language=German Ungültige Konfiguration. Kontext=%1 Pfad=%2 Fehler=%3 Grund=%4 . @@ -60,8 +66,10 @@ MessageId=1020 SymbolicName=START_FAILED Language=English Start failed. Context=%1 Cause=%2 Error=%3 +. Language=French Échec du démarrage. Contexte=%1 Cause=%2 Erreur=%3 +. Language=German Start fehlgeschlagen. Kontext=%1 Ursache=%2 Fehler=%3 . @@ -70,8 +78,10 @@ MessageId=1030 SymbolicName=BOOT_STACKTRACE_WRITTEN Language=English Boot stacktrace written. Context=%1 Path=%2 +. Language=French Trace d’amorçage écrite. Contexte=%1 Chemin=%2 +. Language=German Boot-Stacktrace geschrieben. Kontext=%1 Pfad=%2 . @@ -84,8 +94,10 @@ MessageId=2000 SymbolicName=LISTENER_STARTED Language=English Listener started. Context=%1 Address=%2 Proto=%3 +. Language=French Écouteur démarré. Contexte=%1 Adresse=%2 Protocole=%3 +. Language=German Listener gestartet. Kontext=%1 Adresse=%2 Protokoll=%3 . @@ -94,8 +106,10 @@ MessageId=2001 SymbolicName=LISTENER_BIND_FAILED Language=English Listener bind failed. Context=%1 Address=%2 Error=%3 +. Language=French Échec de l’attachement de l’écouteur. Contexte=%1 Adresse=%2 Erreur=%3 +. Language=German Listener-Bind fehlgeschlagen. Kontext=%1 Adresse=%2 Fehler=%3 . @@ -104,8 +118,10 @@ MessageId=2002 SymbolicName=LISTENER_STOPPED Language=English Listener stopped. Context=%1 Address=%2 Reason=%3 +. Language=French Écouteur arrêté. Contexte=%1 Adresse=%2 Raison=%3 +. Language=German Listener gestoppt. Kontext=%1 Adresse=%2 Grund=%3 . @@ -118,8 +134,10 @@ MessageId=3000 SymbolicName=TLS_CONFIGURED Language=English TLS configured. Context=%1 Source=%2 +. Language=French TLS configuré. Contexte=%1 Source=%2 +. Language=German TLS konfiguriert. Kontext=%1 Quelle=%2 . @@ -128,8 +146,10 @@ MessageId=3001 SymbolicName=TLS_VERIFY_STRICT_DISABLED Language=English TLS strict verification disabled. Context=%1 Mode=%2 +. Language=French Vérification stricte TLS désactivée. Contexte=%1 Mode=%2 +. Language=German Strikte TLS-Überprüfung deaktiviert. Kontext=%1 Modus=%2 . @@ -138,8 +158,10 @@ MessageId=3002 SymbolicName=TLS_CERTIFICATE_REJECTED Language=English Certificate rejected. Context=%1 Subject=%2 Reason=%3 +. Language=French Certificat rejeté. Contexte=%1 Sujet=%2 Raison=%3 +. Language=German Zertifikat abgelehnt. Kontext=%1 Betreff=%2 Grund=%3 . @@ -148,8 +170,10 @@ MessageId=3003 SymbolicName=SYSTEM_CERT_SELECTED Language=English System certificate selected. Context=%1 Thumbprint=%2 Subject=%3 +. Language=French Certificat système sélectionné. Contexte=%1 Empreinte=%2 Sujet=%3 +. Language=German Systemzertifikat ausgewählt. Kontext=%1 Fingerabdruck=%2 Betreff=%3 . @@ -158,8 +182,10 @@ MessageId=3004 SymbolicName=TLS_KEY_LOAD_FAILED Language=English TLS key/cert load failed. Context=%1 Path=%2 Error=%3 Reason=%4 +. Language=French Échec du chargement de la clé/cert TLS. Contexte=%1 Chemin=%2 Erreur=%3 Raison=%4 +. Language=German TLS-Schlüssel/Zertifikat konnte nicht geladen werden. Kontext=%1 Pfad=%2 Fehler=%3 Grund=%4 . @@ -168,8 +194,10 @@ MessageId=3005 SymbolicName=TLS_CERTIFICATE_NAME_MISMATCH Language=English TLS certificate name mismatch. Context=%1 Hostname=%2 Subject=%3 Reason=%4 +. Language=French Nom du certificat TLS non concordant. Contexte=%1 Hôte=%2 Sujet=%3 Raison=%4 +. Language=German TLS-Zertifikat-Namen stimmt nicht überein. Kontext=%1 Hostname=%2 Betreff=%3 Grund=%4 . @@ -178,8 +206,10 @@ MessageId=3006 SymbolicName=TLS_NO_SUITABLE_CERTIFICATE Language=English No suitable certificate found. Context=%1 Error=%2 Issues=%3 +. Language=French Aucun certificat approprié trouvé. Contexte=%1 Erreur=%2 Problèmes=%3 +. Language=German Kein geeignetes Zertifikat gefunden. Kontext=%1 Fehler=%2 Probleme=%3 . @@ -192,8 +222,10 @@ MessageId=4000 SymbolicName=SESSION_OPENED Language=English Session opened. Context=%1 Protocol=%2 Client=%3 Target=%4 TokenId=%5 +. Language=French Session ouverte. Contexte=%1 Protocole=%2 Client=%3 Cible=%4 Jeton=%5 +. Language=German Sitzung geöffnet. Kontext=%1 Protokoll=%2 Client=%3 Ziel=%4 Token=%5 . @@ -202,8 +234,10 @@ MessageId=4001 SymbolicName=SESSION_CLOSED Language=English Session closed. Context=%1 DurationMs=%2 BytesTx=%3 BytesRx=%4 Outcome=%5 +. Language=French Session fermée. Contexte=%1 DuréeMs=%2 OctetsTx=%3 OctetsRx=%4 Résultat=%5 +. Language=German Sitzung geschlossen. Kontext=%1 DauerMs=%2 BytesTx=%3 BytesRx=%4 Ergebnis=%5 . @@ -212,8 +246,10 @@ MessageId=4010 SymbolicName=TOKEN_PROVISIONED Language=English Token provisioned. Context=%1 TokenId=%2 +. Language=French Jeton provisionné. Contexte=%1 Jeton=%2 +. Language=German Token bereitgestellt. Kontext=%1 Token=%2 . @@ -222,8 +258,10 @@ MessageId=4011 SymbolicName=TOKEN_REUSED Language=English Token reused. Context=%1 TokenId=%2 ReuseCount=%3 +. Language=French Jeton réutilisé. Contexte=%1 Jeton=%2 Réutilisations=%3 +. Language=German Token wiederverwendet. Kontext=%1 Token=%2 Anzahl=%3 . @@ -232,8 +270,10 @@ MessageId=4012 SymbolicName=TOKEN_REUSE_LIMIT_EXCEEDED Language=English Token reuse limit exceeded. Context=%1 TokenId=%2 Limit=%3 Reason=%4 +. Language=French Limite de réutilisation du jeton dépassée. Contexte=%1 Jeton=%2 Limite=%3 Raison=%4 +. Language=German Token-Wiederverwendungsgrenze überschritten. Kontext=%1 Token=%2 Limit=%3 Grund=%4 . @@ -242,8 +282,10 @@ MessageId=4030 SymbolicName=RECORDING_STARTED Language=English Recording started. Context=%1 Destination=%2 +. Language=French Enregistrement démarré. Contexte=%1 Destination=%2 +. Language=German Aufnahme gestartet. Kontext=%1 Ziel=%2 . @@ -252,8 +294,10 @@ MessageId=4031 SymbolicName=RECORDING_STOPPED Language=English Recording stopped. Context=%1 Bytes=%2 Files=%3 +. Language=French Enregistrement arrêté. Contexte=%1 Octets=%2 Fichiers=%3 +. Language=German Aufnahme gestoppt. Kontext=%1 Bytes=%2 Dateien=%3 . @@ -262,8 +306,10 @@ MessageId=4032 SymbolicName=RECORDING_ERROR Language=English Recording error. Context=%1 Path=%2 Error=%3 +. Language=French Erreur d’enregistrement. Contexte=%1 Chemin=%2 Erreur=%3 +. Language=German Aufnahmefehler. Kontext=%1 Pfad=%2 Fehler=%3 . @@ -276,8 +322,10 @@ MessageId=5001 SymbolicName=JWT_REJECTED Language=English JWT rejected. Context=%1 ReasonCode=%2 Reason=%3 +. Language=French JWT rejeté. Contexte=%1 CodeRaison=%2 Raison=%3 +. Language=German JWT abgelehnt. Kontext=%1 GrundCode=%2 Grund=%3 . @@ -286,8 +334,10 @@ MessageId=5002 SymbolicName=JWT_ANOMALY Language=English JWT anomaly. Context=%1 Issuer=%2 Audience=%3 Kid=%4 Kind=%5 Detail=%6 +. Language=French Anomalie JWT. Contexte=%1 Émetteur=%2 Audience=%3 Kid=%4 Type=%5 Détail=%6 +. Language=German JWT-Anomalie. Kontext=%1 Aussteller=%2 Audience=%3 Kid=%4 Typ=%5 Detail=%6 . @@ -296,8 +346,10 @@ MessageId=5010 SymbolicName=AUTHORIZATION_DENIED Language=English Authorization denied. Context=%1 Subject=%2 Action=%3 Resource=%4 Rule=%5 Reason=%6 +. Language=French Autorisation refusée. Contexte=%1 Sujet=%2 Action=%3 Ressource=%4 Règle=%5 Raison=%6 +. Language=German Autorisierung verweigert. Kontext=%1 Subjekt=%2 Aktion=%3 Ressource=%4 Regel=%5 Grund=%6 . @@ -306,64 +358,12 @@ MessageId=5090 SymbolicName=AUTH_SUMMARY Language=English Auth summary. Context=%1 IntervalSec=%2 JwtOk=%3 JwtRejected=%4 Denied=%5 ByReason=%6 -Language=French -Résumé d’auth. Contexte=%1 IntervalSec=%2 JwtOk=%3 JwtRejeté=%4 Refusé=%5 ParRaison=%6 -Language=German -Auth-Zusammenfassung. Kontext=%1 IntervallSek=%2 JwtOk=%3 JwtAbgelehnt=%4 Verweigert=%5 NachGrund=%6 -. - -; ====================================================================== -; 6000-6099 Agent Integration -; ====================================================================== - -MessageId=6000 -SymbolicName=USER_SESSION_PROCESS_STARTED -Language=English -User session process started. Context=%1 SessionId=%2 Kind=%3 Exe=%4 -Language=French -Processus de session utilisateur démarré. Contexte=%1 SessionId=%2 Type=%3 Exe=%4 -Language=German -Benutzersitzungsprozess gestartet. Kontext=%1 SessionId=%2 Typ=%3 Exe=%4 -. - -MessageId=6001 -SymbolicName=USER_SESSION_PROCESS_TERMINATED -Language=English -User session process terminated. Context=%1 SessionId=%2 ExitCode=%3 By=%4 -Language=French -Processus de session utilisateur terminé. Contexte=%1 SessionId=%2 CodeSortie=%3 Par=%4 -Language=German -Benutzersitzungsprozess beendet. Kontext=%1 SessionId=%2 ExitCode=%3 Durch=%4 . - -MessageId=6010 -SymbolicName=UPDATER_TASK_ENABLED -Language=English -Updater task enabled. Context=%1 Language=French -Tâche de mise à jour activée. Contexte=%1 -Language=German -Update-Aufgabe aktiviert. Kontext=%1 -. - -MessageId=6011 -SymbolicName=UPDATER_ERROR -Language=English -Updater error. Context=%1 Step=%2 Error=%3 -Language=French -Erreur de mise à jour. Contexte=%1 Étape=%2 Erreur=%3 -Language=German -Update-Fehler. Kontext=%1 Schritt=%2 Fehler=%3 +Résumé d’auth. Contexte=%1 IntervalSec=%2 JwtOk=%3 JwtRejeté=%4 Refusé=%5 ParRaison=%6 . - -MessageId=6020 -SymbolicName=PEDM_ENABLED -Language=English -PEDM enabled. Context=%1 -Language=French -PEDM activé. Contexte=%1 Language=German -PEDM aktiviert. Kontext=%1 +Auth-Zusammenfassung. Kontext=%1 IntervallSek=%2 JwtOk=%3 JwtAbgelehnt=%4 Verweigert=%5 NachGrund=%6 . ; ====================================================================== @@ -374,8 +374,10 @@ MessageId=7010 SymbolicName=RECORDING_STORAGE_LOW Language=English Recording storage low. Context=%1 RemainingBytes=%2 ThresholdBytes=%3 +. Language=French Espace d’enregistrement faible. Contexte=%1 OctetsRestants=%2 Seuil=%3 +. Language=German Aufnahmespeicher niedrig. Kontext=%1 VerbleibendeBytes=%2 Schwelle=%3 . @@ -388,8 +390,10 @@ MessageId=9001 SymbolicName=DEBUG_OPTIONS_ENABLED Language=English Debug options enabled. Context=%1 Options=%2 +. Language=French Options de débogage activées. Contexte=%1 Options=%2 +. Language=German Debug-Optionen aktiviert. Kontext=%1 Optionen=%2 . @@ -398,8 +402,10 @@ MessageId=9002 SymbolicName=XMF_NOT_FOUND Language=English XMF not found. Context=%1 Path=%2 Error=%3 +. Language=French XMF introuvable. Contexte=%1 Chemin=%2 Erreur=%3 +. Language=German XMF nicht gefunden. Kontext=%1 Pfad=%2 Fehler=%3 . diff --git a/package/AgentWindowsManaged.Tests/DevolutionsAgent.Installer.Tests.csproj b/package/AgentWindowsManaged.Tests/DevolutionsAgent.Installer.Tests.csproj new file mode 100644 index 000000000..e54f1240d --- /dev/null +++ b/package/AgentWindowsManaged.Tests/DevolutionsAgent.Installer.Tests.csproj @@ -0,0 +1,21 @@ + + + net48 + latest + false + DevolutionsAgent.Installer.Tests + + + + + + + runtime; build; native; contentfiles; analyzers; buildtransitive + all + + + + + + + diff --git a/package/AgentWindowsManaged.Tests/EventLogSourceRegistryTests.cs b/package/AgentWindowsManaged.Tests/EventLogSourceRegistryTests.cs new file mode 100644 index 000000000..9041cf6fc --- /dev/null +++ b/package/AgentWindowsManaged.Tests/EventLogSourceRegistryTests.cs @@ -0,0 +1,59 @@ +using System; +using System.Reflection; + +using WixSharp; + +using Xunit; + +namespace DevolutionsAgent.Installer.Tests; + +public sealed class EventLogSourceRegistryTests +{ + // The Agent's policy audit trail is only readable if the installer declares the Windows Event + // Log source, so this test pins that declaration against regression. + // + // The broker's audit sink writes under the source name "Devolutions Agent" (WinEvent::new in + // now-package-broker/src/audit.rs), which only calls RegisterEventSourceW. That call succeeds + // without a registry source key, so the event still reaches the Application log; what the key + // provides is the message template. Without a source key named exactly after the runtime source + // name, with EventMessageFile pointing at the executable carrying the message table, Windows + // cannot resolve the template and the entry shows the raw event id and its insertion strings + // instead of the description compiled into DevolutionsAgent.exe. + // + // Nothing fails at build time when the declaration regresses, so this test is what keeps it in + // step with the runtime source name. + // + // This asserts the declared value only. It does not build or install an MSI, so it does not + // validate the WiX pipeline or the [INSTALLDIR] substitution. + [Theory] + [InlineData(true)] + [InlineData(false)] + public void SourceUsesNativeMsiRegistryLifecycle(bool win64) + { + // The installer is an application, referenced for its build output only, so it is loaded by + // name and the helper is reached through reflection. + Type program = System.Reflection.Assembly.Load("DevolutionsAgent").GetType("DevolutionsAgent.Program", throwOnError: true); + MethodInfo method = program.GetMethod( + "CreateEventLogSourceRegistryValue", + BindingFlags.Static | BindingFlags.NonPublic); + RegValue value = Assert.IsType(method.Invoke(null, [win64])); + + Assert.Equal(RegistryHive.LocalMachine, value.Root); + // The key has to match the source name used by the audit sink, or the message is unresolved. + Assert.Equal(@"SYSTEM\CurrentControlSet\Services\EventLog\Application\Devolutions Agent", value.Key); + Assert.Equal("EventMessageFile", value.Name); + Assert.Equal("[INSTALLDIR]DevolutionsAgent.exe", value.Value); + // Pins the architecture flag the installer passes to the MSI component. HKLM\SYSTEM is + // shared between the WOW64 registry views, so this is not what makes a 64-bit reader see + // the source. + Assert.Equal(win64, value.Win64); + // Registered on install and removed on uninstall through the component lifecycle, which + // leaves the source key itself alone. createAndRemoveOnUninstall would delete the whole key + // on uninstall, including anything an administrator or another installer put there. + Assert.Equal(RegistryKeyAction.create, value.RegistryKeyAction); + Assert.False(value.ForceCreateOnInstall); + Assert.False(value.ForceDeleteOnUninstall); + // EventMessageFile has to be REG_SZ, since a REG_MULTI_SZ value is not read as a path. + Assert.Contains("Type=string", value.AttributesDefinition); + } +} diff --git a/package/AgentWindowsManaged/Program.cs b/package/AgentWindowsManaged/Program.cs index d2a246305..f9ff4595a 100644 --- a/package/AgentWindowsManaged/Program.cs +++ b/package/AgentWindowsManaged/Program.cs @@ -348,7 +348,8 @@ static void Main() Win64 = project.Platform == Platform.x64, RegistryKeyAction = RegistryKeyAction.create, Feature = Features.PSU_FEATURE, - } + }, + CreateEventLogSourceRegistryValue(project.Platform == Platform.x64), }; List projectProperties = AgentProperties.Properties.Select(x => x.ToWixSharpProperty()).ToList(); @@ -422,6 +423,21 @@ static void Main() } } + internal static RegValue CreateEventLogSourceRegistryValue(bool win64) => + new( + RegistryHive.LocalMachine, + $"SYSTEM\\CurrentControlSet\\Services\\EventLog\\Application\\{Includes.PRODUCT_NAME}", + "EventMessageFile", + $"[{AgentProperties.InstallDir}]{Includes.EXECUTABLE_NAME}") + { + AttributesDefinition = "Type=string", + Win64 = win64, + // Uninstall removes this value through the ordinary component lifecycle. Do not use + // createAndRemoveOnUninstall: it deletes the whole source key, including values + // written by an administrator or another installer. + RegistryKeyAction = RegistryKeyAction.create, + }; + private static void Project_UnhandledException(ExceptionEventArgs e) { string errorMessage = diff --git a/testsuite/Cargo.toml b/testsuite/Cargo.toml index 1e3cad10e..a40691073 100644 --- a/testsuite/Cargo.toml +++ b/testsuite/Cargo.toml @@ -31,6 +31,7 @@ typed-builder = "0.21" tokio-tungstenite = { version = "0.29", features = ["rustls-tls-native-roots"] } [dev-dependencies] +agent-sysevent-codes.path = "../crates/agent-sysevent-codes" agent-tunnel = { path = "../crates/agent-tunnel", features = ["test-utils"] } agent-tunnel-libsql = { path = "../crates/agent-tunnel-libsql" } agent-tunnel-proto = { path = "../crates/agent-tunnel-proto", features = ["serde"] } @@ -57,6 +58,7 @@ rustls-pemfile = "2" rustls-pki-types = "1" serde_json = "1" sysevent.path = "../crates/sysevent" +sysevent-codes.path = "../crates/sysevent-codes" tempfile = "3" test-utils.path = "../crates/test-utils" tokio-rustls = { version = "0.26", features = ["ring"] } diff --git a/testsuite/tests/sysevent/message_catalog.rs b/testsuite/tests/sysevent/message_catalog.rs new file mode 100644 index 000000000..ab3b89c47 --- /dev/null +++ b/testsuite/tests/sysevent/message_catalog.rs @@ -0,0 +1,546 @@ +//! Verifies that each product's declared event codes and Windows message catalog stay aligned. + +use std::path::{Path, PathBuf}; + +use sysevent::Entry; + +const GATEWAY_CATALOG: &str = "devolutions-gateway/devolutions-gateway.mc"; +const AGENT_CATALOG: &str = "devolutions-agent/devolutions-agent.mc"; + +/// A declared code set, the single catalog that must hold exactly its codes, and every builder of +/// those codes paired with the entry it produces. +struct DeclaredCodeSet { + codes_crate: &'static str, + codes: &'static [(&'static str, u32)], + catalog: &'static str, + events: fn() -> Vec<(u32, Entry)>, +} + +/// The Gateway and the Agent own separate code tables, so each catalog holds the codes of its own +/// crate and nothing else. A code shared by both products is declared in both crates and appears in +/// both catalogs. +const DECLARED_CODE_SETS: &[DeclaredCodeSet] = &[ + DeclaredCodeSet { + codes_crate: "sysevent-codes", + codes: sysevent_codes::DECLARED_CODES, + catalog: GATEWAY_CATALOG, + events: gateway_events, + }, + DeclaredCodeSet { + codes_crate: "agent-sysevent-codes", + codes: agent_sysevent_codes::DECLARED_CODES, + catalog: AGENT_CATALOG, + events: agent_events, + }, +]; + +#[test] +fn every_catalog_defines_exactly_its_declared_codes() { + for declared in DECLARED_CODE_SETS { + let DeclaredCodeSet { + codes_crate, + codes, + catalog, + .. + } = declared; + assert!(!codes.is_empty(), "{codes_crate} declares no event code"); + + let path = catalog_path(catalog); + let content = read(&path); + let defined = catalog_codes(&content, &path); + + // The code is the value the runtime passes to ReportEventW, so a name bound to the wrong + // number must fail here even though every declared name is present. + let mut disagreements: Vec = Vec::new(); + for (name, code) in codes.iter().copied() { + match defined.iter().find(|(defined_name, _)| defined_name.as_str() == name) { + None => disagreements.push(format!("{name} is missing")), + Some((_, defined_code)) if *defined_code == code => {} + Some((_, defined_code)) => disagreements.push(format!( + "{name} is MessageId={defined_code}, but {codes_crate} declares {code}" + )), + } + } + for (name, code) in &defined { + if !codes.iter().any(|(declared_name, _)| *declared_name == name.as_str()) { + disagreements.push(format!( + "{name} is MessageId={code}, which {codes_crate} does not declare; a catalog \ + holds exactly the codes of its own product" + )); + } + } + assert!( + disagreements.is_empty(), + "{} and {codes_crate} disagree: {}", + path.display(), + disagreements.join("; ") + ); + + assert_eq!( + defined.len(), + codes.len(), + "{} declares {} messages for {} {codes_crate} codes; each code needs exactly one \ + message", + path.display(), + defined.len(), + codes.len() + ); + } +} + +#[test] +fn every_catalog_message_terminates_each_translation() { + for declared in DECLARED_CODE_SETS { + let DeclaredCodeSet { catalog, .. } = declared; + let path = catalog_path(catalog); + let content = read(&path); + assert!( + content.starts_with('\u{feff}'), + "{}: mc.exe requires a UTF-8 BOM to avoid decoding translations as ANSI", + path.display() + ); + + for (name, code) in catalog_codes(&content, &path) { + let mut lines = message_block(&content, code).lines(); + let mut languages = Vec::new(); + while let Some(line) = lines.next() { + let Some(language) = line.strip_prefix("Language=") else { + continue; + }; + languages.push(language); + let mut terminated = false; + for text in lines.by_ref() { + if text == "." { + terminated = true; + break; + } + assert!( + !text.starts_with("Language="), + "{}: MessageId={code} {language} lacks a message terminator", + path.display() + ); + } + assert!( + terminated, + "{}: MessageId={code} {language} lacks a message terminator", + path.display() + ); + } + languages.sort_unstable(); + assert_eq!( + languages, + ["English", "French", "German"], + "{}: MessageId={code} {name} must define each translation once", + path.display() + ); + } + } +} + +#[test] +fn every_code_builder_inserts_the_message_then_every_field() { + for declared in DECLARED_CODE_SETS { + let DeclaredCodeSet { + codes_crate, + codes, + catalog, + events, + } = declared; + let path = catalog_path(catalog); + let catalog = read(&path); + + let events = events(); + let mut covered: Vec = events.iter().map(|(code, _)| *code).collect(); + covered.sort_unstable(); + let mut declared_codes: Vec = codes.iter().map(|(_, code)| *code).collect(); + declared_codes.sort_unstable(); + assert_eq!( + covered, declared_codes, + "every {codes_crate} code needs a builder here, so its insertion strings stay checked" + ); + + for (code, entry) in events { + assert_eq!( + entry.event_code, + Some(code), + "the builder for MessageId={code} must declare that event code" + ); + + // The Windows Event Log sink passes the message text as the first insertion string, then + // one string per field, so a message needs exactly one insertion per field plus one. + let count = u32::try_from(entry.fields.len() + 1).expect("the entry has few fields"); + let expected: Vec = (1..=count).collect(); + + let messages = catalog_messages(&catalog, code); + assert_eq!(messages.len(), 3, "{}: MessageId={code} translations", path.display()); + for message in messages { + assert_eq!( + insertions(message), + expected, + "{}: MessageId={code} must use %1 as the message and %2..%{count} as its fields: {message}", + path.display() + ); + } + } + } +} + +/// Every declared Gateway event, each paired with the entry its builder produces. +fn gateway_events() -> Vec<(u32, Entry)> { + let path = Path::new("C:\\ProgramData\\Devolutions\\Gateway\\gateway.json"); + + let mut events = vec![ + ( + sysevent_codes::SERVICE_STARTED, + sysevent_codes::service_started("2026.3.0"), + ), + ( + sysevent_codes::SERVICE_STOPPING, + sysevent_codes::service_stopping("received stop control code"), + ), + ( + sysevent_codes::CONFIG_INVALID, + sysevent_codes::config_invalid("invalid config", path), + ), + ( + sysevent_codes::START_FAILED, + sysevent_codes::start_failed("failed to bind", "service_start"), + ), + ( + sysevent_codes::BOOT_STACKTRACE_WRITTEN, + sysevent_codes::boot_stacktrace_written(path), + ), + ( + sysevent_codes::LISTENER_STARTED, + sysevent_codes::listener_started("127.0.0.1:7171", "tcp"), + ), + ( + sysevent_codes::LISTENER_BIND_FAILED, + sysevent_codes::listener_bind_failed("127.0.0.1:7171", "address in use"), + ), + ( + sysevent_codes::LISTENER_STOPPED, + sysevent_codes::listener_stopped("127.0.0.1:7171", "shutdown"), + ), + (sysevent_codes::TLS_CONFIGURED, sysevent_codes::tls_configured("file")), + ( + sysevent_codes::TLS_VERIFY_STRICT_DISABLED, + sysevent_codes::tls_verify_strict_disabled("compat"), + ), + ( + sysevent_codes::TLS_CERTIFICATE_REJECTED, + sysevent_codes::tls_certificate_rejected("CN=gateway", "missing_san"), + ), + ( + sysevent_codes::SYSTEM_CERT_SELECTED, + sysevent_codes::system_cert_selected("", "CN=gateway"), + ), + ( + sysevent_codes::TLS_KEY_LOAD_FAILED, + sysevent_codes::tls_key_load_failed(path, "permission denied"), + ), + ( + sysevent_codes::TLS_CERTIFICATE_NAME_MISMATCH, + sysevent_codes::tls_certificate_name_mismatch("gateway.example.com", "CN=gateway"), + ), + ( + sysevent_codes::TLS_NO_SUITABLE_CERTIFICATE, + sysevent_codes::tls_no_suitable_certificate("no usable certificate", "expired"), + ), + ( + sysevent_codes::SESSION_OPENED, + sysevent_codes::session_opened("RDP", "10.0.0.1", "srv01", "token_id"), + ), + ( + sysevent_codes::SESSION_CLOSED, + sysevent_codes::session_closed(1000, 1024, 2048, "ok"), + ), + ( + sysevent_codes::TOKEN_PROVISIONED, + sysevent_codes::token_provisioned("token_id"), + ), + ( + sysevent_codes::TOKEN_REUSED, + sysevent_codes::token_reused("token_id", 1), + ), + ( + sysevent_codes::TOKEN_REUSE_LIMIT_EXCEEDED, + sysevent_codes::token_reuse_limit_exceeded("token_id", 2), + ), + ( + sysevent_codes::RECORDING_STARTED, + sysevent_codes::recording_started("C:\\recordings"), + ), + ( + sysevent_codes::RECORDING_STOPPED, + sysevent_codes::recording_stopped(1024, 1), + ), + ( + sysevent_codes::RECORDING_ERROR, + sysevent_codes::recording_error(path, "no space left"), + ), + ( + sysevent_codes::JWT_REJECTED, + sysevent_codes::jwt_rejected("expired", "the token expired"), + ), + ( + sysevent_codes::JWT_ANOMALY, + sysevent_codes::jwt_anomaly("issuer", "audience", "kid", "clock_skew", "detail"), + ), + ( + sysevent_codes::AUTHORIZATION_DENIED, + sysevent_codes::authorization_denied("subject", "action", "resource", "rule"), + ), + ( + sysevent_codes::AUTH_SUMMARY, + sysevent_codes::auth_summary(60, 10, 2, 1, "{}"), + ), + ( + sysevent_codes::RECORDING_STORAGE_LOW, + sysevent_codes::recording_storage_low(1024, 4096), + ), + ( + sysevent_codes::DEBUG_OPTIONS_ENABLED, + sysevent_codes::debug_options_enabled("verbose"), + ), + ( + sysevent_codes::XMF_NOT_FOUND, + sysevent_codes::xmf_not_found(path, "not found"), + ), + ]; + + events.sort_unstable_by_key(|(code, _)| *code); + events +} + +/// Every declared Agent event, each paired with the entry its builder produces. +fn agent_events() -> Vec<(u32, Entry)> { + let path = Path::new("C:\\ProgramData\\Devolutions\\Agent\\policy.json"); + + let mut events = vec![ + ( + agent_sysevent_codes::SERVICE_STARTED, + agent_sysevent_codes::service_started("2026.3.0"), + ), + ( + agent_sysevent_codes::SERVICE_STOPPING, + agent_sysevent_codes::service_stopping("received stop control code"), + ), + ( + agent_sysevent_codes::CONFIG_INVALID, + agent_sysevent_codes::config_invalid("invalid config", path), + ), + ( + agent_sysevent_codes::START_FAILED, + agent_sysevent_codes::start_failed("failed to bind", "service_start"), + ), + ( + agent_sysevent_codes::BOOT_STACKTRACE_WRITTEN, + agent_sysevent_codes::boot_stacktrace_written(path), + ), + ( + agent_sysevent_codes::USER_SESSION_PROCESS_STARTED, + agent_sysevent_codes::user_session_process_started(1, "console", "DevolutionsSession.exe"), + ), + ( + agent_sysevent_codes::USER_SESSION_PROCESS_TERMINATED, + agent_sysevent_codes::user_session_process_terminated(1, 0, "user"), + ), + ( + agent_sysevent_codes::UPDATER_TASK_ENABLED, + agent_sysevent_codes::updater_task_enabled(), + ), + ( + agent_sysevent_codes::UPDATER_ERROR, + agent_sysevent_codes::updater_error("download", "invalid signature"), + ), + (agent_sysevent_codes::PEDM_ENABLED, agent_sysevent_codes::pedm_enabled()), + ( + agent_sysevent_codes::POLICY_WRITE_ATTEMPTED, + agent_sysevent_codes::policy_write_attempted("S-1-5-18", "devolutions-agent.exe", "policy_write", path), + ), + ( + agent_sysevent_codes::POLICY_WRITE_DENIED, + agent_sysevent_codes::policy_write_denied( + "S-1-5-18", + "devolutions-agent.exe", + "policy_write", + path, + "request_rejected", + ), + ), + ( + agent_sysevent_codes::POLICY_CREATE_FAILED, + agent_sysevent_codes::policy_write_failed( + agent_sysevent_codes::POLICY_CREATE_FAILED, + "Policy creation failed", + "S-1-5-18", + "devolutions-agent.exe", + "policy_write", + path, + "create", + "failed", + "invalid_draft", + ), + ), + ( + agent_sysevent_codes::POLICY_CREATE_SUCCEEDED, + agent_sysevent_codes::policy_write_succeeded( + agent_sysevent_codes::POLICY_CREATE_SUCCEEDED, + "Policy creation succeeded", + "S-1-5-18", + "devolutions-agent.exe", + path, + "00000000-0000-0000-0000-000000000000", + "0", + "11111111-1111-1111-1111-111111111111", + 1, + "policy_write", + "create", + "succeeded", + ), + ), + ( + agent_sysevent_codes::POLICY_CHANGE_FAILED, + agent_sysevent_codes::policy_write_failed( + agent_sysevent_codes::POLICY_CHANGE_FAILED, + "Policy change failed", + "S-1-5-18", + "devolutions-agent.exe", + "policy_write", + path, + "change", + "stale_conflict", + "stale_store_token", + ), + ), + ( + agent_sysevent_codes::POLICY_CHANGE_SUCCEEDED, + agent_sysevent_codes::policy_write_succeeded( + agent_sysevent_codes::POLICY_CHANGE_SUCCEEDED, + "Policy change succeeded", + "S-1-5-18", + "devolutions-agent.exe", + path, + "11111111-1111-1111-1111-111111111111", + "1", + "22222222-2222-2222-2222-222222222222", + 2, + "policy_write", + "change", + "succeeded", + ), + ), + ( + agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_APPLIED, + agent_sysevent_codes::policy_external_change_applied(path, "22222222-2222-2222-2222-222222222222", 2), + ), + ( + agent_sysevent_codes::POLICY_EXTERNAL_CHANGE_REJECTED, + agent_sysevent_codes::policy_external_change_rejected(path, "invalid"), + ), + ]; + + events.sort_unstable_by_key(|(code, _)| *code); + events +} + +fn read(path: &Path) -> String { + std::fs::read_to_string(path).unwrap_or_else(|error| panic!("failed to read {}: {error}", path.display())) +} + +fn catalog_path(catalog: &str) -> PathBuf { + // The testsuite sits at the repository root, next to the product crates holding the catalogs. + Path::new(env!("CARGO_MANIFEST_DIR")) + .parent() + .expect("the testsuite sits in the repository root") + .join(catalog) +} + +/// Every message of a catalog, as its symbolic name and message id, in file order. +fn catalog_codes(content: &str, path: &Path) -> Vec<(String, u32)> { + let mut codes = Vec::new(); + let mut lines = content.lines(); + + while let Some(line) = lines.next() { + let Some(id) = line.strip_prefix("MessageId=") else { + continue; + }; + let id = id.trim(); + let name = lines + .next() + .unwrap_or_else(|| panic!("{}: MessageId={id} without a symbolic name", path.display())); + let name = name.strip_prefix("SymbolicName=").unwrap_or_else(|| { + panic!( + "{}: MessageId={id} must be followed by its SymbolicName, found {name:?}", + path.display() + ) + }); + + codes.push(( + name.trim().to_owned(), + id.parse() + .unwrap_or_else(|error| panic!("{}: MessageId={id} is not an event code: {error}", path.display())), + )); + } + + codes +} + +/// The message of each translation inside the `MessageId=` block. +fn catalog_messages(catalog: &str, code: u32) -> Vec<&str> { + let mut messages = Vec::new(); + let mut lines = message_block(catalog, code).lines(); + while let Some(line) = lines.next() { + if line.starts_with("Language=") { + messages.push(lines.next().unwrap_or_default()); + } + } + messages +} + +/// The lines following `MessageId=`, up to the next message. Each line is compared whole, +/// which keeps a code from matching a longer code such as `800` against `8001`, and the line ending +/// is trimmed so a catalog checked out with CRLF endings reads the same as one with LF. +fn message_block(content: &str, code: u32) -> &str { + let marker = format!("MessageId={code}"); + let mut start = None; + let mut end = content.len(); + let mut offset = 0; + + for line in content.split_inclusive('\n') { + let trimmed = line.trim_end_matches(['\n', '\r']); + if trimmed == marker.as_str() { + start = Some(offset + line.len()); + } else if start.is_some() && trimmed.starts_with("MessageId=") { + end = offset; + break; + } + offset += line.len(); + } + + match start { + Some(start) => &content[start..end], + None => panic!("missing MessageId={code}"), + } +} + +/// Insertion indices (`%1`, `%2`, ...) referenced by a catalog message, in ascending order. +fn insertions(message: &str) -> Vec { + let mut indices = Vec::new(); + let mut remaining = message; + + while let Some(percent) = remaining.find('%') { + remaining = &remaining[percent + 1..]; + let trailing = remaining.trim_start_matches(|character: char| character.is_ascii_digit()); + if trailing.len() == remaining.len() { + continue; + } + let (index, rest) = remaining.split_at(remaining.len() - trailing.len()); + indices.push(index.parse().expect("a catalog insertion index is a number")); + remaining = rest; + } + + indices.sort_unstable(); + indices +} diff --git a/testsuite/tests/sysevent/mod.rs b/testsuite/tests/sysevent/mod.rs index 1315fc9ae..65ffb4fdc 100644 --- a/testsuite/tests/sysevent/mod.rs +++ b/testsuite/tests/sysevent/mod.rs @@ -1,4 +1,5 @@ //! Integration tests for system-wide logging with fake sink implementations +mod message_catalog; mod syslog; mod winevent;