From b0a4e2ea93fafc4d65d474f3ada616a0ad5e19d5 Mon Sep 17 00:00:00 2001
From: Ariver <ar@Arm1.local>
Date: Sun, 12 Jul 2026 11:39:35 +0800
Subject: [PATCH] feat: bind helper stream timing markers
---
src/service.rs | 456 +++++++++++++++++++++++++++++++++++++++++++++++++++++---
1 files changed, 426 insertions(+), 30 deletions(-)
diff --git a/src/service.rs b/src/service.rs
index a579636..1e3e0c2 100644
--- a/src/service.rs
+++ b/src/service.rs
@@ -4,7 +4,7 @@
io::{BufRead, BufReader, Read, Write},
net::{TcpListener, TcpStream},
process::{Child, Command, Stdio},
- sync::{Arc, Mutex},
+ sync::{Arc, Mutex, mpsc},
thread,
time::{Duration, SystemTime, UNIX_EPOCH},
};
@@ -17,6 +17,8 @@
const DEFAULT_BIND_ADDR: &str = "127.0.0.1:18080";
const HTTP_READ_LIMIT_BYTES: usize = 1024 * 1024;
const DEFAULT_START_READY_TIMEOUT_MS: u64 = 10_000;
+const ANCHORED_CALLBACK_MAX_ATTEMPTS: u32 = 3;
+const ANCHORED_CALLBACK_RETRY_DELAY: Duration = Duration::from_millis(50);
pub fn service_mode_enabled() -> bool {
env::args().any(|arg| arg == "service" || arg == "--service")
@@ -192,7 +194,7 @@
trace_id,
);
}
- let child = match spawn_worker(&start_req, &profile, &state.config) {
+ let child = match spawn_worker(&start_req, &profile, &state.config, trace_id.as_deref()) {
Ok(value) => value,
Err(spawn_error) => {
warn!(
@@ -214,11 +216,27 @@
let runtime_session_id = format!("rt_{}", start_req.call_id);
let mut child = child;
let child_stdout = child.stdout.take();
+ let event_callback_url = start_req
+ .event_callback
+ .as_ref()
+ .and_then(|value| value.url.clone())
+ .filter(|value| !value.trim().is_empty());
+ let event_callback_token = Some(profile.event_callback_token.clone());
+ let event_callback_sender = if event_callback_url.is_some() {
+ let (sender, receiver) = mpsc::channel();
+ spawn_event_callback_worker(receiver);
+ Some(sender)
+ } else {
+ None
+ };
let session = HelperSession {
call_id: start_req.call_id.clone(),
trace_id: trace_id.clone(),
runtime_session_nonce: start_req.runtime_session_nonce.clone(),
runtime_session_id,
+ event_callback_url,
+ event_callback_token,
+ event_callback_sender,
status: "STARTING".to_string(),
bot_participant_joined: false,
bot_track_ready: false,
@@ -334,6 +352,7 @@
req: &SessionStartRequest,
profile: &AuthProfile,
config: &ServiceConfig,
+ trace_id: Option<&str>,
) -> Result<Child> {
let exe = env::current_exe().context("failed to resolve helper executable")?;
let mut command = Command::new(exe);
@@ -342,15 +361,15 @@
.env("CV_CALL_ID", &req.call_id)
.env(
"CV_TRACE_ID",
- req.trace_id
- .clone()
+ trace_id
+ .map(str::to_string)
.unwrap_or_else(|| format!("trace_{}", req.call_id)),
)
.env("CV_RUNTIME_CALL_ID", &req.call_id)
.env(
"CV_RUNTIME_TRACE_ID",
- req.trace_id
- .clone()
+ trace_id
+ .map(str::to_string)
.unwrap_or_else(|| format!("trace_{}", req.call_id)),
)
.env("CV_RUNTIME_SESSION_NONCE", &req.runtime_session_nonce)
@@ -373,6 +392,48 @@
if let Some(runtime) = &req.runtime {
if let Some(value) = &runtime.turn_artifact_dir {
command.env("CV_RUNTIME_TURN_ARTIFACT_DIR", value);
+ }
+ if let Some(value) = runtime.vad_rms_threshold {
+ command.env("CV_VAD_RMS_THRESHOLD", value.to_string());
+ }
+ if let Some(value) = runtime.vad_peak_threshold {
+ command.env("CV_VAD_PEAK_THRESHOLD", value.to_string());
+ }
+ if let Some(value) = runtime.vad_start_frames {
+ command.env("CV_VAD_START_FRAMES", value.to_string());
+ }
+ if let Some(value) = runtime.vad_end_silence_ms {
+ command.env("CV_VAD_END_SILENCE_MS", value.to_string());
+ }
+ if let Some(value) = runtime.vad_min_speech_ms {
+ command.env("CV_VAD_MIN_SPEECH_MS", value.to_string());
+ }
+ if let Some(value) = runtime.vad_max_turn_ms {
+ command.env("CV_VAD_MAX_TURN_MS", value.to_string());
+ }
+ if let Some(value) = runtime.vad_initial_ignore_ms {
+ command.env("CV_VAD_INITIAL_IGNORE_MS", value.to_string());
+ }
+ if let Some(value) = runtime.vad_post_greeting_delay_ms {
+ command.env("CV_VAD_POST_GREETING_DELAY_MS", value.to_string());
+ }
+ if let Some(value) = runtime.asr_streaming_enabled {
+ command.env("CV_RUNTIME_ASR_STREAM_ENABLED", value.to_string());
+ }
+ if let Some(value) = &runtime.asr_stream_url {
+ command.env("CV_RUNTIME_ASR_STREAM_URL", value);
+ }
+ if let Some(value) = runtime.asr_realtime_enabled {
+ command.env("CV_RUNTIME_ASR_REALTIME_ENABLED", value.to_string());
+ }
+ if let Some(value) = &runtime.asr_realtime_url {
+ command.env("CV_RUNTIME_ASR_REALTIME_URL", value);
+ }
+ if let Some(value) = runtime.asr_realtime_chunk_duration_ms {
+ command.env(
+ "CV_RUNTIME_ASR_REALTIME_CHUNK_DURATION_MS",
+ value.to_string(),
+ );
}
if let Some(true) = runtime.audio_debug_dump_enabled {
if let Some(value) = &config.audio_debug_dump_dir {
@@ -434,34 +495,270 @@
.and_then(Value::as_str)
.unwrap_or("worker_event");
let result = value.get("result").and_then(Value::as_str).unwrap_or("ok");
- let Ok(mut sessions) = state.sessions.lock() else {
- return;
+ let queued_callback = {
+ let Ok(mut sessions) = state.sessions.lock() else {
+ return;
+ };
+ let Some(session) = sessions.get_mut(call_id) else {
+ return;
+ };
+ let turn_id = value.get("turnId").and_then(Value::as_str);
+ let terminal = matches!(
+ event_name,
+ "turn_completed" | "turn_failed" | "turn_cancelled"
+ );
+ if event_name == "turn_bridge_requested" {
+ session.active_turn_id = turn_id.map(str::to_string);
+ }
+ session.last_event_type = Some(event_name.to_string());
+ session.last_event_at = now_millis();
+ let callback = if is_anchored_callback(value) && !anchored_callback_bound(session, value) {
+ warn!(
+ call_id = %call_id,
+ trace_id = ?session.trace_id,
+ event_name = %event_name,
+ "helper rejected unbound anchored callback"
+ );
+ None
+ } else {
+ build_event_callback_dispatch(session, value)
+ };
+ let callback_sender = session.event_callback_sender.clone();
+ if result != "ok" {
+ session.status = "FAILED".to_string();
+ session.bot_participant_joined = false;
+ session.bot_track_ready = false;
+ } else {
+ match event_name {
+ "helper_worker_started" => {
+ session.status = "STARTING".to_string();
+ }
+ "bot_participant_joined" => {
+ session.bot_participant_joined = true;
+ }
+ "bot_track_ready" => {
+ session.bot_participant_joined = true;
+ session.bot_track_ready = true;
+ session.status = "STARTED".to_string();
+ }
+ _ => {}
+ }
+ }
+ if terminal && turn_id == session.active_turn_id.as_deref() {
+ session.active_turn_id = None;
+ }
+ callback.zip(callback_sender)
};
- let Some(session) = sessions.get_mut(call_id) else {
- return;
+ if let Some((callback, sender)) = queued_callback {
+ if sender.send(callback).is_err() {
+ warn!(
+ call_id = %call_id,
+ event_name = %event_name,
+ "helper event callback queue closed"
+ );
+ }
+ }
+}
+
+fn build_event_callback_dispatch(
+ session: &HelperSession,
+ value: &Value,
+) -> Option<EventCallbackDispatch> {
+ let url = session
+ .event_callback_url
+ .as_ref()
+ .filter(|value| !value.trim().is_empty())?
+ .clone();
+ let token = session
+ .event_callback_token
+ .as_ref()
+ .filter(|value| !value.trim().is_empty())?
+ .clone();
+ Some(EventCallbackDispatch {
+ url,
+ token,
+ call_id: session.call_id.clone(),
+ trace_id: session.trace_id.clone(),
+ runtime_session_nonce: session.runtime_session_nonce.clone(),
+ payload: value.clone(),
+ })
+}
+
+fn spawn_event_callback_worker(receiver: mpsc::Receiver<EventCallbackDispatch>) {
+ thread::spawn(move || {
+ run_event_callback_worker(receiver, deliver_event_callback);
+ });
+}
+
+fn run_event_callback_worker<F>(receiver: mpsc::Receiver<EventCallbackDispatch>, mut deliver: F)
+where
+ F: FnMut(EventCallbackDispatch),
+{
+ while let Ok(callback) = receiver.recv() {
+ deliver(callback);
+ }
+}
+
+fn deliver_event_callback(callback: EventCallbackDispatch) {
+ deliver_event_callback_with(callback, post_event_callback);
+}
+
+fn deliver_event_callback_with<F>(callback: EventCallbackDispatch, mut post: F)
+where
+ F: FnMut(&EventCallbackDispatch) -> Result<u16>,
+{
+ let event_name = callback
+ .payload
+ .get("eventName")
+ .and_then(Value::as_str)
+ .unwrap_or("worker_event")
+ .to_string();
+ let max_attempts = if is_anchored_callback(&callback.payload) {
+ ANCHORED_CALLBACK_MAX_ATTEMPTS
+ } else {
+ 1
};
- session.last_event_type = Some(event_name.to_string());
- session.last_event_at = now_millis();
- if result != "ok" {
- session.status = "FAILED".to_string();
- session.bot_participant_joined = false;
- session.bot_track_ready = false;
- return;
+ for attempt in 1..=max_attempts {
+ let result = post(&callback);
+ let retry =
+ attempt < max_attempts && !matches!(&result, Ok(status) if (200..300).contains(status));
+ match result {
+ Ok(status) if (200..300).contains(&status) => {
+ info!(
+ call_id = %callback.call_id,
+ trace_id = ?callback.trace_id,
+ event_name = %event_name,
+ status = status,
+ attempt = attempt,
+ "helper event callback delivered"
+ );
+ return;
+ }
+ Ok(status) => {
+ warn!(
+ call_id = %callback.call_id,
+ trace_id = ?callback.trace_id,
+ event_name = %event_name,
+ status = status,
+ attempt = attempt,
+ "helper event callback rejected"
+ );
+ }
+ Err(error) => {
+ warn!(
+ call_id = %callback.call_id,
+ trace_id = ?callback.trace_id,
+ event_name = %event_name,
+ attempt = attempt,
+ error = %error,
+ "helper event callback failed"
+ );
+ }
+ }
+ if retry {
+ thread::sleep(ANCHORED_CALLBACK_RETRY_DELAY);
+ }
}
- match event_name {
- "helper_worker_started" => {
- session.status = "STARTING".to_string();
- }
- "bot_participant_joined" => {
- session.bot_participant_joined = true;
- }
- "bot_track_ready" => {
- session.bot_participant_joined = true;
- session.bot_track_ready = true;
- session.status = "STARTED".to_string();
- }
- _ => {}
+}
+
+fn is_anchored_callback(payload: &Value) -> bool {
+ matches!(
+ payload.get("eventName").and_then(Value::as_str),
+ Some("helper_first_reply_audio_chunk_received" | "bot_reply_first_audio_frame_written")
+ ) && payload.get("serverDeltaSource").and_then(Value::as_str) == Some("stream_anchor_monotonic")
+}
+
+fn anchored_callback_bound(session: &HelperSession, payload: &Value) -> bool {
+ let extension = payload.get("extension");
+ let anchor_id = extension
+ .and_then(|value| value.get("streamAnchorId"))
+ .and_then(Value::as_str);
+ let anchor_base = extension
+ .and_then(|value| value.get("streamAnchorServerDeltaMs"))
+ .and_then(Value::as_u64);
+ let elapsed = extension
+ .and_then(|value| value.get("anchorElapsedMs"))
+ .and_then(Value::as_u64);
+ let delta = payload.get("serverDeltaMs").and_then(Value::as_u64);
+ let expected_delta =
+ anchor_base.and_then(|base| elapsed.and_then(|value| base.checked_add(value)));
+ let expected_nonce_hash = crate::runtime_session_nonce_hash(&session.runtime_session_nonce);
+ payload.get("callId").and_then(Value::as_str) == Some(session.call_id.as_str())
+ && payload.get("traceId").and_then(Value::as_str) == session.trace_id.as_deref()
+ && payload.get("turnId").and_then(Value::as_str) == session.active_turn_id.as_deref()
+ && extension
+ .and_then(|value| value.get("streamTimingVersion"))
+ .and_then(Value::as_u64)
+ == Some(1)
+ && anchor_id.is_some_and(|value| (16..=64).contains(&value.len()) && value.is_ascii())
+ && extension
+ .and_then(|value| value.get("runtimeSessionNonceHash"))
+ .and_then(Value::as_str)
+ == Some(expected_nonce_hash.as_str())
+ && extension
+ .and_then(|value| value.get("segmentSeq"))
+ .and_then(Value::as_u64)
+ == Some(1)
+ && extension
+ .and_then(|value| value.get("streamTimingValidation"))
+ .and_then(Value::as_str)
+ == Some("bound")
+ && elapsed.is_some_and(|value| value <= 5_000)
+ && delta == expected_delta
+}
+
+fn post_event_callback(callback: &EventCallbackDispatch) -> Result<u16> {
+ let (host, path) = parse_http_url(&callback.url)?;
+ let body = serde_json::to_vec(&callback.payload)?;
+ let mut stream = TcpStream::connect(&host)
+ .with_context(|| format!("failed to connect callback host {host}"))?;
+ stream.set_read_timeout(Some(Duration::from_secs(3)))?;
+ stream.set_write_timeout(Some(Duration::from_secs(3)))?;
+ let trace_header = callback.trace_id.clone().unwrap_or_default();
+ let request = format!(
+ "POST {path} HTTP/1.1\r\n\
+ Host: {host}\r\n\
+ Authorization: Bearer {}\r\n\
+ X-CV-Runtime-Token: {}\r\n\
+ X-CV-Call-Id: {}\r\n\
+ X-CV-Trace-Id: {}\r\n\
+ X-CV-Runtime-Session-Nonce: {}\r\n\
+ Content-Type: application/json\r\n\
+ Content-Length: {}\r\n\
+ Connection: close\r\n\
+ \r\n",
+ callback.token,
+ callback.token,
+ callback.call_id,
+ trace_header,
+ callback.runtime_session_nonce,
+ body.len()
+ );
+ stream.write_all(request.as_bytes())?;
+ stream.write_all(&body)?;
+ stream.flush()?;
+ let mut response = String::new();
+ stream.read_to_string(&mut response)?;
+ response
+ .lines()
+ .next()
+ .and_then(|line| line.split_whitespace().nth(1))
+ .and_then(|value| value.parse::<u16>().ok())
+ .ok_or_else(|| anyhow!("callback response status missing"))
+}
+
+fn parse_http_url(url: &str) -> Result<(String, String)> {
+ let Some(rest) = url.strip_prefix("http://") else {
+ return Err(anyhow!("only http callback url is supported"));
+ };
+ let (host, path) = match rest.split_once('/') {
+ Some((host, path)) => (host, format!("/{path}")),
+ None => (rest, "/".to_string()),
+ };
+ if host.trim().is_empty() {
+ return Err(anyhow!("callback host missing"));
}
+ Ok((host.to_string(), path))
}
enum WaitReadyResult {
@@ -692,6 +989,7 @@
struct AuthProfile {
helper_auth_token: String,
turn_bridge_token: String,
+ event_callback_token: String,
}
impl AuthProfile {
@@ -707,11 +1005,24 @@
let turn_bridge_token = env::var(format!("CV_TURN_BRIDGE_TOKEN_{suffix}"))
.or_else(|_| env::var("CV_RUNTIME_TURN_BRIDGE_TOKEN"))
.ok()?;
+ let event_callback_token = env::var(format!("CV_EVENT_CALLBACK_TOKEN_{suffix}"))
+ .or_else(|_| env::var("CV_RUNTIME_EVENT_CALLBACK_TOKEN"))
+ .unwrap_or_else(|_| turn_bridge_token.clone());
Some(Self {
helper_auth_token,
turn_bridge_token,
+ event_callback_token,
})
}
+}
+
+struct EventCallbackDispatch {
+ url: String,
+ token: String,
+ call_id: String,
+ trace_id: Option<String>,
+ runtime_session_nonce: String,
+ payload: Value,
}
struct ServiceState {
@@ -724,6 +1035,9 @@
trace_id: Option<String>,
runtime_session_nonce: String,
runtime_session_id: String,
+ event_callback_url: Option<String>,
+ event_callback_token: Option<String>,
+ event_callback_sender: Option<mpsc::Sender<EventCallbackDispatch>>,
status: String,
bot_participant_joined: bool,
bot_track_ready: bool,
@@ -742,6 +1056,7 @@
runtime_session_nonce: String,
livekit: LiveKitStart,
turn_bridge: Option<TurnBridgeStart>,
+ event_callback: Option<EventCallbackStart>,
auth_profile: Option<String>,
audio: Option<AudioStart>,
runtime: Option<RuntimeStart>,
@@ -765,6 +1080,12 @@
#[derive(Deserialize)]
#[serde(rename_all = "camelCase")]
+struct EventCallbackStart {
+ url: Option<String>,
+}
+
+#[derive(Deserialize)]
+#[serde(rename_all = "camelCase")]
struct AudioStart {
first_audio_source: Option<String>,
greeting_audio: Option<GreetingAudioStart>,
@@ -781,7 +1102,20 @@
#[serde(rename_all = "camelCase")]
struct RuntimeStart {
turn_artifact_dir: Option<String>,
+ vad_rms_threshold: Option<f64>,
+ vad_peak_threshold: Option<f64>,
+ vad_start_frames: Option<u32>,
+ vad_end_silence_ms: Option<u64>,
+ vad_min_speech_ms: Option<u64>,
+ vad_max_turn_ms: Option<u64>,
+ vad_initial_ignore_ms: Option<u64>,
+ vad_post_greeting_delay_ms: Option<u64>,
audio_debug_dump_enabled: Option<bool>,
+ asr_streaming_enabled: Option<bool>,
+ asr_stream_url: Option<String>,
+ asr_realtime_enabled: Option<bool>,
+ asr_realtime_url: Option<String>,
+ asr_realtime_chunk_duration_ms: Option<u64>,
}
#[derive(Default, Deserialize)]
@@ -906,3 +1240,65 @@
Err(_) => default_value,
}
}
+
+#[cfg(test)]
+mod tests {
+ use super::{EventCallbackDispatch, deliver_event_callback_with, run_event_callback_worker};
+ use anyhow::Result;
+ use serde_json::{Value, json};
+ use std::{cell::RefCell, rc::Rc, sync::mpsc};
+
+ #[test]
+ fn same_session_callback_retries_m7_before_terminal() {
+ let (sender, receiver) = mpsc::channel();
+ let dispatch = |payload| EventCallbackDispatch {
+ url: "http://callback.test/endpoint".to_string(),
+ token: "test-token".to_string(),
+ call_id: "call-1".to_string(),
+ trace_id: Some("trace-1".to_string()),
+ runtime_session_nonce: "test-nonce".to_string(),
+ payload,
+ };
+ sender
+ .send(dispatch(json!({
+ "eventName": "bot_reply_first_audio_frame_written",
+ "serverDeltaSource": "stream_anchor_monotonic"
+ })))
+ .expect("queue m7");
+ sender
+ .send(dispatch(json!({"eventName": "turn_completed"})))
+ .expect("queue terminal");
+ drop(sender);
+
+ let observed = Rc::new(RefCell::new(Vec::new()));
+ let observed_for_worker = observed.clone();
+ run_event_callback_worker(receiver, move |callback| {
+ let observed_for_post = observed_for_worker.clone();
+ let mut m7_attempt = 0;
+ deliver_event_callback_with(callback, move |dispatch| -> Result<u16> {
+ let event_name = dispatch
+ .payload
+ .get("eventName")
+ .and_then(Value::as_str)
+ .expect("event name")
+ .to_string();
+ observed_for_post.borrow_mut().push(event_name.clone());
+ if event_name == "bot_reply_first_audio_frame_written" && m7_attempt == 0 {
+ m7_attempt += 1;
+ Ok(500)
+ } else {
+ Ok(200)
+ }
+ });
+ });
+
+ assert_eq!(
+ vec![
+ "bot_reply_first_audio_frame_written",
+ "bot_reply_first_audio_frame_written",
+ "turn_completed"
+ ],
+ *observed.borrow()
+ );
+ }
+}
--
Gitblit v1.9.3