From f3237616a0bc95cf50fd790f07b72128c624b947 Mon Sep 17 00:00:00 2001
From: cai <cai@nbcai.cc>
Date: Wed, 12 Aug 2026 12:41:44 +0800
Subject: [PATCH] Bind fixture ACK evidence to probe hashes
---
src/main.rs | 534 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++---
1 files changed, 504 insertions(+), 30 deletions(-)
diff --git a/src/main.rs b/src/main.rs
index cd45c4d..68b8cea 100644
--- a/src/main.rs
+++ b/src/main.rs
@@ -6,6 +6,7 @@
borrow::Cow,
collections::HashSet,
env, fs,
+ future::Future,
path::{Path, PathBuf},
sync::{
Arc,
@@ -66,6 +67,21 @@
const CONTROLLED_FIXTURE_PROBE_RECHECK_DELAY: Duration = Duration::from_millis(25);
const CONTROLLED_FIXTURE_PROBE_TTL: Duration = Duration::from_millis(250);
+const CONTROLLED_FIXTURE_ACK_RESULTS: [&str; 4] =
+ ["observed", "rejected", "timeout", "publish_failed"];
+const CONTROLLED_FIXTURE_REJECT_REASONS: [&str; 10] = [
+ "missing_attributes",
+ "wrong_source",
+ "missing_sequence",
+ "wrong_sequence",
+ "wrong_participant",
+ "expired",
+ "duplicate_or_old_sequence",
+ "no_current_participant",
+ "ack_publish_failed",
+ "unknown",
+];
+
#[derive(Debug, Deserialize)]
#[serde(rename_all = "camelCase")]
struct ControlledFixtureAttributeProbe {
@@ -95,9 +111,12 @@
reject_reason: Option<&'static str>,
}
-#[derive(Debug)]
+#[derive(Clone, Debug)]
struct PendingControlledFixtureProbe {
sender: ParticipantIdentity,
+ call_id_hash: String,
+ call_trace_id_hash: String,
+ generation: u64,
sequence: String,
expires_at: Instant,
}
@@ -110,6 +129,153 @@
.iter()
.map(|byte| format!("{byte:02x}"))
.collect()
+}
+
+fn controlled_fixture_ack_classification(
+ decision: Result<(), &'static str>,
+) -> (&'static str, Option<&'static str>, bool) {
+ match decision {
+ Ok(()) => ("observed", None, true),
+ Err("timeout") => ("timeout", Some("expired"), false),
+ Err(reason) if CONTROLLED_FIXTURE_REJECT_REASONS.contains(&reason) => {
+ ("rejected", Some(reason), false)
+ }
+ Err(_) => ("rejected", Some("unknown"), false),
+ }
+}
+
+fn record_controlled_fixture_probe_event(
+ stage: &'static str,
+ call_id_hash: &str,
+ trace_id_hash: &str,
+ generation: u64,
+ sequence: &str,
+ observed: bool,
+ ack_result: Option<&'static str>,
+ reject_reason: Option<&'static str>,
+) {
+ debug_assert!(ack_result.is_none_or(|value| CONTROLLED_FIXTURE_ACK_RESULTS.contains(&value)));
+ debug_assert!(
+ reject_reason.is_none_or(|value| CONTROLLED_FIXTURE_REJECT_REASONS.contains(&value))
+ );
+ if let Some(ack_result) = ack_result {
+ info!(
+ event = "controlled_fixture_attribute_probe",
+ stage,
+ observed,
+ ack_result,
+ reject_reason = reject_reason.unwrap_or("unknown"),
+ call_id_hash,
+ trace_id_hash,
+ generation,
+ sequence_hash = %sha256_hex(sequence),
+ "runtime helper controlled fixture probe state"
+ );
+ } else if let Some(reject_reason) = reject_reason {
+ info!(
+ event = "controlled_fixture_attribute_probe",
+ stage,
+ observed,
+ reject_reason,
+ call_id_hash,
+ trace_id_hash,
+ generation,
+ sequence_hash = %sha256_hex(sequence),
+ "runtime helper controlled fixture probe state"
+ );
+ } else {
+ info!(
+ event = "controlled_fixture_attribute_probe",
+ stage,
+ observed,
+ call_id_hash,
+ trace_id_hash,
+ generation,
+ sequence_hash = %sha256_hex(sequence),
+ "runtime helper controlled fixture probe state"
+ );
+ }
+}
+
+fn record_controlled_fixture_attribute_decision(
+ decision: Result<(), &'static str>,
+ call_id_hash: &str,
+ trace_id_hash: &str,
+ generation: u64,
+ sequence: &str,
+) -> (&'static str, Option<&'static str>, bool) {
+ let classification = controlled_fixture_ack_classification(decision);
+ record_controlled_fixture_probe_event(
+ "attributes_classified",
+ call_id_hash,
+ trace_id_hash,
+ generation,
+ sequence,
+ classification.2,
+ Some(classification.0),
+ classification.1,
+ );
+ classification
+}
+
+async fn complete_controlled_fixture_ack_publish<F, E>(
+ publish: F,
+ observed: bool,
+ ack_result: &'static str,
+ reject_reason: Option<&'static str>,
+ call_id_hash: &str,
+ trace_id_hash: &str,
+ generation: u64,
+ sequence: &str,
+ acknowledged_probe_sequences: &mut HashSet<String>,
+) -> bool
+where
+ F: Future<Output = Result<(), E>>,
+{
+ if publish.await.is_ok() {
+ record_controlled_fixture_probe_event(
+ "ack_publish_completed",
+ call_id_hash,
+ trace_id_hash,
+ generation,
+ sequence,
+ observed,
+ Some(ack_result),
+ reject_reason,
+ );
+ acknowledged_probe_sequences.insert(sequence.to_string());
+ observed
+ } else {
+ record_controlled_fixture_probe_event(
+ "ack_publish_completed",
+ call_id_hash,
+ trace_id_hash,
+ generation,
+ sequence,
+ false,
+ Some("publish_failed"),
+ Some("ack_publish_failed"),
+ );
+ false
+ }
+}
+
+fn controlled_fixture_ack_from_probe(
+ probe: &PendingControlledFixtureProbe,
+ observed: bool,
+ reject_reason: Option<&'static str>,
+) -> ControlledFixtureAttributeAck {
+ ControlledFixtureAttributeAck {
+ message_type: CONTROLLED_FIXTURE_ACK_TOPIC,
+ protocol_version: CONTROLLED_FIXTURE_PROTOCOL_VERSION,
+ call_id_hash: probe.call_id_hash.clone(),
+ call_trace_id_hash: probe.call_trace_id_hash.clone(),
+ generation: probe.generation,
+ client_fixture_sequence: probe.sequence.clone(),
+ result: if observed { "observed" } else { "rejected" },
+ input_source_category: observed.then_some("controlled_fixture"),
+ reject_reason,
+ }
}
fn controlled_fixture_probe(
@@ -134,6 +300,9 @@
}
Some(PendingControlledFixtureProbe {
sender: sender.clone(),
+ call_id_hash: probe.call_id_hash,
+ call_trace_id_hash: probe.call_trace_id_hash,
+ generation: probe.generation,
sequence: probe.client_fixture_sequence,
expires_at: Instant::now() + CONTROLLED_FIXTURE_PROBE_TTL,
})
@@ -966,20 +1135,18 @@
track_source = %track_source,
"runtime helper user_track_subscribed"
);
- let pending_sequence = pending_probe.as_ref().map(|probe| probe.sequence.clone());
+ let pending_binding = pending_probe.clone();
let participant_for_probe = participant.clone();
let probe_result = process_controlled_fixture_probe(
&mut pending_probe,
&mut acknowledged_probe_sequences,
Some(&participant_for_probe),
&sink,
- &call_id,
- &trace_id,
user_participant_identity.as_deref(),
)
.await;
let observer_started = start_observer_after_controlled_fixture_probe(
- pending_sequence.is_some(),
+ pending_binding.is_some(),
probe_result,
|| {
spawn_user_audio_frame_observer(
@@ -999,6 +1166,27 @@
);
},
);
+ if let Some(probe) = pending_binding.as_ref() {
+ let (ack_result, reject_reason, observed) = match probe_result {
+ Some(true) => (Some("observed"), None, true),
+ Some(false) => (Some("rejected"), Some("unknown"), false),
+ None => (None, Some("no_current_participant"), false),
+ };
+ record_controlled_fixture_probe_event(
+ if observer_started {
+ "audio_observer_allowed"
+ } else {
+ "audio_observer_blocked"
+ },
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ observed,
+ ack_result,
+ reject_reason,
+ );
+ }
if !observer_started {
warn!(
call_id = %call_id,
@@ -1019,6 +1207,16 @@
serde_json::from_slice::<ControlledFixtureAttributeProbe>(&payload)
{
if acknowledged_probe_sequences.contains(&probe.client_fixture_sequence) {
+ record_controlled_fixture_probe_event(
+ "data_received",
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.client_fixture_sequence,
+ false,
+ Some("rejected"),
+ Some("duplicate_or_old_sequence"),
+ );
continue;
}
}
@@ -1029,13 +1227,23 @@
&sender.identity(),
user_participant_identity.as_deref(),
);
+ if let Some(probe) = pending_probe.as_ref() {
+ record_controlled_fixture_probe_event(
+ "data_received",
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ false,
+ None,
+ None,
+ );
+ }
process_controlled_fixture_probe(
&mut pending_probe,
&mut acknowledged_probe_sequences,
current_user_participant.as_ref(),
&sink,
- &call_id,
- &trace_id,
user_participant_identity.as_deref(),
)
.await;
@@ -1086,21 +1294,62 @@
acknowledged_probe_sequences: &mut HashSet<String>,
participant: Option<&RemoteParticipant>,
sink: &BotAudioOutputSink,
- call_id: &str,
- trace_id: &str,
expected_participant: Option<&str>,
) -> Option<bool> {
let Some(probe) = pending_probe.take() else {
return None;
};
- if acknowledged_probe_sequences.contains(&probe.sequence) || Instant::now() > probe.expires_at {
+ if acknowledged_probe_sequences.contains(&probe.sequence) {
+ record_controlled_fixture_probe_event(
+ "attributes_classified",
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ false,
+ Some("rejected"),
+ Some("duplicate_or_old_sequence"),
+ );
+ return Some(false);
+ }
+ if Instant::now() > probe.expires_at {
+ record_controlled_fixture_probe_event(
+ "attributes_classified",
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ false,
+ Some("timeout"),
+ Some("expired"),
+ );
return Some(false);
}
let Some(participant) = participant else {
+ record_controlled_fixture_probe_event(
+ "attributes_classified",
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ false,
+ None,
+ Some("no_current_participant"),
+ );
*pending_probe = Some(probe);
return None;
};
if participant.identity() != probe.sender {
+ record_controlled_fixture_probe_event(
+ "attributes_classified",
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ false,
+ Some("rejected"),
+ Some("wrong_participant"),
+ );
return Some(false);
}
let decision = observe_controlled_fixture_attributes(
@@ -1111,36 +1360,49 @@
|| participant.attributes(),
)
.await;
- let (result, input_source_category, reject_reason) = match decision {
- Ok(()) => ("observed", Some("controlled_fixture"), None),
- Err(reason) => ("rejected", None, Some(reason)),
- };
- let ack = ControlledFixtureAttributeAck {
- message_type: CONTROLLED_FIXTURE_ACK_TOPIC,
- protocol_version: CONTROLLED_FIXTURE_PROTOCOL_VERSION,
- call_id_hash: sha256_hex(call_id),
- call_trace_id_hash: sha256_hex(trace_id),
- generation: CONTROLLED_FIXTURE_GENERATION,
- client_fixture_sequence: probe.sequence.clone(),
- result,
- input_source_category,
- reject_reason,
- };
+ let (ack_result, reject_reason, observed) = record_controlled_fixture_attribute_decision(
+ decision,
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ );
+ let ack = controlled_fixture_ack_from_probe(&probe, observed, reject_reason);
let payload = match serde_json::to_vec(&ack) {
Ok(payload) => payload,
Err(_) => return Some(false),
};
let local_participant = sink.room.local_participant();
+ record_controlled_fixture_probe_event(
+ "ack_publish_started",
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ observed,
+ Some(ack_result),
+ reject_reason,
+ );
let publish = local_participant.publish_data(DataPacket {
payload,
topic: Some(CONTROLLED_FIXTURE_ACK_TOPIC.to_string()),
reliable: true,
destination_identities: vec![probe.sender],
});
- if publish.await.is_ok() {
- acknowledged_probe_sequences.insert(probe.sequence);
- }
- Some(result == "observed")
+ Some(
+ complete_controlled_fixture_ack_publish(
+ publish,
+ observed,
+ ack_result,
+ reject_reason,
+ &probe.call_id_hash,
+ &probe.call_trace_id_hash,
+ probe.generation,
+ &probe.sequence,
+ acknowledged_probe_sequences,
+ )
+ .await,
+ )
}
async fn handle_finished_turn(
@@ -4392,7 +4654,7 @@
io::{Read, Write},
net::TcpListener,
sync::{
- Arc,
+ Arc, Mutex,
atomic::{AtomicUsize, Ordering},
mpsc,
},
@@ -4410,6 +4672,30 @@
participant: String,
attributes: HashMap<String, String>,
},
+ }
+
+ #[derive(Clone, Default)]
+ struct CapturedLogs(Arc<Mutex<Vec<u8>>>);
+
+ struct CapturedLogWriter(Arc<Mutex<Vec<u8>>>);
+
+ impl Write for CapturedLogWriter {
+ fn write(&mut self, bytes: &[u8]) -> std::io::Result<usize> {
+ self.0.lock().unwrap().extend_from_slice(bytes);
+ Ok(bytes.len())
+ }
+
+ fn flush(&mut self) -> std::io::Result<()> {
+ Ok(())
+ }
+ }
+
+ impl<'a> tracing_subscriber::fmt::MakeWriter<'a> for CapturedLogs {
+ type Writer = CapturedLogWriter;
+
+ fn make_writer(&'a self) -> Self::Writer {
+ CapturedLogWriter(self.0.clone())
+ }
}
fn drive_pre_audio_order_test_seam(events: &[PreAudioOrderEvent]) -> Vec<&'static str> {
@@ -4992,6 +5278,9 @@
controlled_fixture_probe(&payload, call_id, trace_id, &sender, Some("user-1"))
.expect("valid probe");
assert_eq!(pending.sequence, "fixture-01");
+ assert_eq!(pending.call_id_hash, sha256_hex(call_id));
+ assert_eq!(pending.call_trace_id_hash, sha256_hex(trace_id));
+ assert_eq!(pending.generation, CONTROLLED_FIXTURE_GENERATION);
assert!(
controlled_fixture_probe(&payload, call_id, "other-trace", &sender, Some("user-1"),)
.is_none()
@@ -5063,6 +5352,191 @@
);
}
+ #[test]
+ fn controlled_fixture_probe_failure_log_is_fixed_redacted_and_has_no_audio_effect() {
+ let logs = CapturedLogs::default();
+ let subscriber = tracing_subscriber::fmt()
+ .without_time()
+ .with_ansi(false)
+ .with_writer(logs.clone())
+ .finish();
+ let call_id = "private-call-value";
+ let trace_id = "private-trace-value";
+ let sequence = "private-sequence-value";
+ let call_id_hash = sha256_hex(call_id);
+ let trace_id_hash = sha256_hex(trace_id);
+ let mut observer_starts = 0;
+ tracing::subscriber::with_default(subscriber, || {
+ let decision = Err("wrong_source");
+ let (ack_result, reject_reason, observed) =
+ record_controlled_fixture_attribute_decision(
+ decision,
+ &call_id_hash,
+ &trace_id_hash,
+ CONTROLLED_FIXTURE_GENERATION,
+ sequence,
+ );
+ record_controlled_fixture_probe_event(
+ "audio_observer_blocked",
+ &call_id_hash,
+ &trace_id_hash,
+ CONTROLLED_FIXTURE_GENERATION,
+ sequence,
+ observed,
+ Some(ack_result),
+ reject_reason,
+ );
+ assert!(!start_observer_after_controlled_fixture_probe(
+ true,
+ Some(observed),
+ || observer_starts += 1,
+ ));
+ });
+ let output = String::from_utf8(logs.0.lock().unwrap().clone()).unwrap();
+ assert!(output.contains("ack_result=\"rejected\""));
+ assert!(output.contains("reject_reason=\"wrong_source\""));
+ assert!(output.contains("observed=false"));
+ assert!(output.contains(&sha256_hex(call_id)));
+ assert!(output.contains(&sha256_hex(trace_id)));
+ assert!(output.contains(&sha256_hex(sequence)));
+ assert!(!output.contains(call_id));
+ assert!(!output.contains(trace_id));
+ assert!(!output.contains(sequence));
+ assert_eq!(observer_starts, 0);
+ }
+
+ #[test]
+ fn controlled_fixture_probe_observed_and_failure_enums_are_stable() {
+ assert_eq!(
+ controlled_fixture_ack_classification(Ok(())),
+ ("observed", None, true)
+ );
+ assert_eq!(
+ controlled_fixture_ack_classification(Err("timeout")),
+ ("timeout", Some("expired"), false)
+ );
+ for reason in [
+ "missing_attributes",
+ "wrong_source",
+ "missing_sequence",
+ "wrong_sequence",
+ "wrong_participant",
+ ] {
+ assert_eq!(
+ controlled_fixture_ack_classification(Err(reason)),
+ ("rejected", Some(reason), false)
+ );
+ }
+ assert_eq!(
+ controlled_fixture_ack_classification(Err("unclassified")),
+ ("rejected", Some("unknown"), false)
+ );
+ }
+
+ #[test]
+ fn production_probe_binding_drives_rejected_and_observed_ack_without_local_rehash() {
+ let request_call_hash = "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa";
+ let request_trace_hash = "bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb";
+ let probe = PendingControlledFixtureProbe {
+ sender: ParticipantIdentity("user-1".to_string()),
+ call_id_hash: request_call_hash.to_string(),
+ call_trace_id_hash: request_trace_hash.to_string(),
+ generation: CONTROLLED_FIXTURE_GENERATION,
+ sequence: "fixture-01".to_string(),
+ expires_at: Instant::now() + CONTROLLED_FIXTURE_PROBE_TTL,
+ };
+
+ let (ack_result, reject_reason, observed) =
+ controlled_fixture_ack_classification(Err("wrong_sequence"));
+ let rejected_ack = controlled_fixture_ack_from_probe(&probe, observed, reject_reason);
+ let rejected_json = serde_json::to_value(&rejected_ack).unwrap();
+ let mut rejected_observer_starts = 0;
+ assert_eq!(ack_result, "rejected");
+ assert_eq!(rejected_json["callIdHash"], request_call_hash);
+ assert_eq!(rejected_json["callTraceIdHash"], request_trace_hash);
+ assert_eq!(rejected_json["rejectReason"], "wrong_sequence");
+ assert!(!start_observer_after_controlled_fixture_probe(
+ true,
+ Some(observed),
+ || rejected_observer_starts += 1,
+ ));
+ assert_eq!(rejected_observer_starts, 0);
+
+ let (ack_result, reject_reason, observed) = controlled_fixture_ack_classification(Ok(()));
+ let observed_ack = controlled_fixture_ack_from_probe(&probe, observed, reject_reason);
+ let observed_json = serde_json::to_value(&observed_ack).unwrap();
+ let mut observed_observer_starts = 0;
+ assert_eq!(ack_result, "observed");
+ assert_eq!(observed_json["callIdHash"], request_call_hash);
+ assert_eq!(observed_json["callTraceIdHash"], request_trace_hash);
+ assert!(observed_json.get("rejectReason").is_none());
+ assert!(start_observer_after_controlled_fixture_probe(
+ true,
+ Some(observed),
+ || observed_observer_starts += 1,
+ ));
+ assert_eq!(observed_observer_starts, 1);
+ }
+
+ #[tokio::test]
+ async fn production_ack_publish_failure_keeps_observer_session_and_audio_closed() {
+ let mut acknowledged = HashSet::new();
+ let probe_result = complete_controlled_fixture_ack_publish(
+ async { Err::<(), ()>(()) },
+ true,
+ "observed",
+ None,
+ "call-publish-failure",
+ "trace-publish-failure",
+ CONTROLLED_FIXTURE_GENERATION,
+ "fixture-01",
+ &mut acknowledged,
+ )
+ .await;
+ let mut observer_starts = 0;
+ let mut session_starts = 0;
+ let mut audio_starts = 0;
+ let mut speaking_starts = 0;
+ assert!(!start_observer_after_controlled_fixture_probe(
+ true,
+ Some(probe_result),
+ || {
+ observer_starts += 1;
+ session_starts += 1;
+ audio_starts += 1;
+ speaking_starts += 1;
+ },
+ ));
+ assert!(!probe_result);
+ assert!(acknowledged.is_empty());
+ assert_eq!(observer_starts, 0);
+ assert_eq!(session_starts, 0);
+ assert_eq!(audio_starts, 0);
+ assert_eq!(speaking_starts, 0);
+
+ let observed_result = complete_controlled_fixture_ack_publish(
+ async { Ok::<(), ()>(()) },
+ true,
+ "observed",
+ None,
+ "call-publish-success",
+ "trace-publish-success",
+ CONTROLLED_FIXTURE_GENERATION,
+ "fixture-02",
+ &mut acknowledged,
+ )
+ .await;
+ let mut successful_observer_starts = 0;
+ assert!(start_observer_after_controlled_fixture_probe(
+ true,
+ Some(observed_result),
+ || successful_observer_starts += 1,
+ ));
+ assert!(observed_result);
+ assert!(acknowledged.contains("fixture-02"));
+ assert_eq!(successful_observer_starts, 1);
+ }
+
#[tokio::test]
async fn production_attribute_observation_accepts_server_visibility_within_probe_ttl() {
let expected = HashMap::from([
--
Gitblit v1.9.3