From 6986c9c533f8a0e7a59cfd57abd8210a4a2f1b1c Mon Sep 17 00:00:00 2001 From: audit Date: Wed, 12 Aug 2026 13:56:20 +1000 Subject: [PATCH] fix(victauri-test): IPC checkpoint cannot miss a same-millisecond call The pre-release GPT-5.5 adversarial audit of the v0.8.8 candidate found one real issue: ipc_calls_since filters with a strict timestamp > checkpoint comparison, so a call logged in the same millisecond immediately after create_ipc_checkpoint returned was silently invisible. create_ipc_checkpoint now waits until the local clock has advanced past the checkpoint millisecond before returning (bounded at 5ms against clock skew), so calls made after the checkpoint cannot share the boundary timestamp. No API change; semver-checks vs 0.8.7 stays clean. Also adds a stateless-MCP auth regression test pinning Bearer enforcement on the 2026-07-28 server/discover lifecycle method, and folds both into the 0.8.8 CHANGELOG entry. Full local gate re-verified post-restart: fmt, clippy x4 (default / no-default / release / sqlite) -D warnings, workspace tests (+sqlite), doc -D warnings, semver-checks (no update required), cargo deny, cargo audit, install-gate self-test, doc-count lint. Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_01B3UneTjEcPtULZuER1BSvY --- CHANGELOG.md | 8 +++ .../tests/integration_tests.rs | 56 +++++++++++++++++++ crates/victauri-test/src/client.rs | 40 +++++++++++-- crates/victauri-test/tests/client_tests.rs | 48 ++++++++++++++++ 4 files changed, 146 insertions(+), 6 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2c65625..e5ffffe 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -27,6 +27,14 @@ vs 0.8.7: no semver update required — `^0.8` consumers pick it up automaticall `calls_since` filters by it with a 1000-entry read — immune to the window's position. Method signatures unchanged; verified live (the two failing 4DA dogfood tests pass with the fix, plus two new mock-server regression tests). +- **`victauri-test`: IPC checkpoints can no longer miss a call sharing the checkpoint's + millisecond** (found by the pre-release GPT-5.5 adversarial audit). `ipc_calls_since` filters + with a strict `timestamp > checkpoint`, so a call logged in the same millisecond immediately + after `create_ipc_checkpoint` returned was silently invisible. The checkpoint now waits until + the local clock has advanced past the checkpoint millisecond before returning (bounded at 5 ms + against clock skew), so calls made after the checkpoint cannot share the boundary timestamp. + Regression test pins the same-ms boundary; a second new test pins Bearer-auth enforcement on + the `2026-07-28` `server/discover` lifecycle method for stateless MCP. ### Changed diff --git a/crates/victauri-plugin/tests/integration_tests.rs b/crates/victauri-plugin/tests/integration_tests.rs index fb8026c..467566c 100644 --- a/crates/victauri-plugin/tests/integration_tests.rs +++ b/crates/victauri-plugin/tests/integration_tests.rs @@ -840,6 +840,62 @@ async fn stateless_still_enforces_auth() { ); } +#[tokio::test] +async fn stateless_auth_gates_discover_lifecycle() { + let base = start_stateless_auth_test_server(test_state(), &["main"], "secret-token").await; + let client = reqwest::Client::new(); + + let discover = serde_json::json!({ + "jsonrpc": "2.0", + "id": 1, + "method": "server/discover", + "params": { + "_meta": { + "io.modelcontextprotocol/protocolVersion": "2026-07-28", + "io.modelcontextprotocol/clientCapabilities": {} + } + } + }); + + let unauth = client + .post(format!("{base}/mcp")) + .header("Content-Type", "application/json") + .header("Accept", "application/json, text/event-stream") + .header("MCP-Protocol-Version", "2026-07-28") + .header("Mcp-Method", "server/discover") + .json(&discover) + .send() + .await + .unwrap(); + assert_eq!( + unauth.status(), + reqwest::StatusCode::UNAUTHORIZED, + "server/discover must be rejected before rmcp dispatch without Bearer auth" + ); + + let authed = client + .post(format!("{base}/mcp")) + .header("Content-Type", "application/json") + .header("Accept", "application/json, text/event-stream") + .header("MCP-Protocol-Version", "2026-07-28") + .header("Mcp-Method", "server/discover") + .header("Authorization", "Bearer secret-token") + .json(&discover) + .send() + .await + .unwrap(); + assert!( + authed.status().is_success(), + "authenticated server/discover should reach the MCP handler, got {}", + authed.status() + ); + let body: serde_json::Value = authed.json().await.unwrap(); + assert!( + body["result"]["supportedVersions"].is_array(), + "authenticated response should be a DiscoverResult: {body}" + ); +} + #[tokio::test] async fn mcp_full_session_lists_tools() { let base = start_test_server(test_state(), &["main"]).await; diff --git a/crates/victauri-test/src/client.rs b/crates/victauri-test/src/client.rs index 8a6a02e..461b830 100644 --- a/crates/victauri-test/src/client.rs +++ b/crates/victauri-test/src/client.rs @@ -1,10 +1,33 @@ use serde::Deserialize; use serde_json::{Value, json}; +use std::time::{Duration, SystemTime, UNIX_EPOCH}; use crate::assertions::VerifyBuilder; use crate::error::TestError; use crate::visual::{VisualDiff, VisualOptions}; +const IPC_CHECKPOINT_CLOCK_ADVANCE_CAP: Duration = Duration::from_millis(5); + +fn current_epoch_ms() -> Option { + SystemTime::now() + .duration_since(UNIX_EPOCH) + .ok() + .map(|d| u64::try_from(d.as_millis()).unwrap_or(u64::MAX)) +} + +async fn wait_past_ipc_checkpoint_ms(checkpoint_ms: u64) { + let Some(now_ms) = current_epoch_ms() else { + return; + }; + if checkpoint_ms == 0 || checkpoint_ms < now_ms { + return; + } + + let sleep_ms = checkpoint_ms.saturating_sub(now_ms).saturating_add(1); + let cap_ms = u64::try_from(IPC_CHECKPOINT_CLOCK_ADVANCE_CAP.as_millis()).unwrap_or(u64::MAX); + tokio::time::sleep(Duration::from_millis(sleep_ms.min(cap_ms))).await; +} + // ── Typed Response Structs (Phase 4E) ─────────────────────────────────────── /// Structured plugin information returned by [`VictauriClient::plugin_info`]. @@ -1421,10 +1444,13 @@ impl VictauriClient { /// Returns the maximum entry `timestamp` (epoch milliseconds) currently /// visible in the IPC log, or `0` when the log is empty. Pass this value to /// [`VictauriClient::ipc_calls_since`] to get only the calls that occurred - /// after the checkpoint. Timestamp-based rather than length-based because - /// the server's log tools return a capped sliding window of the newest - /// entries — a positional checkpoint stops working once a busy app exceeds - /// the cap. + /// after the checkpoint. For non-empty logs this method waits until the + /// local clock has advanced past the checkpoint millisecond before it + /// returns, so calls made immediately after the checkpoint cannot share the + /// boundary timestamp and be filtered out by the strict `>` comparison. + /// Timestamp-based rather than length-based because the server's log tools + /// return a capped sliding window of the newest entries — a positional + /// checkpoint stops working once a busy app exceeds the cap. /// /// # Errors /// @@ -1435,11 +1461,13 @@ impl VictauriClient { // snapshot breaks (always-empty `calls_since`) once the app has logged // more calls than the cap. Timestamps are window-position-independent. let entries = self.ipc_log_entries().await?; - Ok(entries + let checkpoint_ms = entries .iter() .filter_map(|e| e.get("timestamp").and_then(Value::as_u64)) .max() - .unwrap_or(0) as usize) + .unwrap_or(0); + wait_past_ipc_checkpoint_ms(checkpoint_ms).await; + Ok(checkpoint_ms as usize) } // ── Typed Response Methods (Phase 4E) ──────────────────────────────────── diff --git a/crates/victauri-test/tests/client_tests.rs b/crates/victauri-test/tests/client_tests.rs index 13afdb0..59d2763 100644 --- a/crates/victauri-test/tests/client_tests.rs +++ b/crates/victauri-test/tests/client_tests.rs @@ -1,5 +1,6 @@ use std::sync::Arc; use std::sync::atomic::{AtomicU64, Ordering}; +use std::time::{SystemTime, UNIX_EPOCH}; use axum::Router; use axum::body::Body; @@ -15,6 +16,16 @@ use victauri_test::{ assert_no_a11y_violations, assert_performance_budget, assert_state_matches, }; +fn test_epoch_ms() -> u64 { + u64::try_from( + SystemTime::now() + .duration_since(UNIX_EPOCH) + .expect("system clock must be after Unix epoch") + .as_millis(), + ) + .expect("epoch milliseconds must fit in u64") +} + // ── Mock MCP Server ─────────────────────────────────────────────────────── #[derive(Clone)] @@ -1162,6 +1173,43 @@ async fn ipc_checkpoint_survives_sliding_window_cap() { ); } +#[tokio::test] +async fn ipc_checkpoint_waits_past_current_millisecond_boundary() { + let state = MockState::new(); + let port = start_mock_server(state.clone()).await; + let mut client = VictauriClient::connect(port).await.unwrap(); + + let boundary = test_epoch_ms().saturating_add(2); + let before = vec![json!({"command": "before", "timestamp": boundary})]; + *state.response_override.lock().await = Some(json!({ + "content": [{"type": "text", "text": serde_json::to_string(&before).unwrap()}] + })); + + let cp = client.create_ipc_checkpoint().await.unwrap(); + assert_eq!(cp, boundary as usize); + + let after_ts = test_epoch_ms(); + assert!( + after_ts > boundary, + "checkpoint should not return until the next observable IPC timestamp is greater \ + than the checkpoint boundary: after_ts={after_ts}, boundary={boundary}" + ); + + let after = vec![ + json!({"command": "before", "timestamp": boundary}), + json!({"command": "after", "timestamp": after_ts}), + ]; + *state.response_override.lock().await = Some(json!({ + "content": [{"type": "text", "text": serde_json::to_string(&after).unwrap()}] + })); + + let since = client.get_ipc_calls_since(cp).await.unwrap(); + assert_eq!( + since, + vec![json!({"command": "after", "timestamp": after_ts})] + ); +} + #[tokio::test] async fn ipc_checkpoint_empty_log_returns_all_later_entries() { // Zero checkpoint (empty log at checkpoint time): everything that appears