Ariver
2026-07-12 b0a4e2ea93fafc4d65d474f3ada616a0ad5e19d5
feat: bind helper stream timing markers
2 files modified
655 ■■■■■ changed files
src/main.rs 428 ●●●●● patch | view | raw | blame | history
src/service.rs 227 ●●●●● patch | view | raw | blame | history
src/main.rs
@@ -34,6 +34,7 @@
use reqwest::Client;
use serde::{Deserialize, Serialize};
use serde_json::json;
use sha2::{Digest, Sha256};
use tokio::time::{sleep, sleep_until, timeout};
use tokio::{
    sync::{mpsc, mpsc::UnboundedReceiver, watch},
@@ -51,6 +52,11 @@
const PCM_16K_SAMPLE_RATE_HZ: u32 = 16_000;
const BOT_NUM_CHANNELS: u16 = 1;
const TRACK_NAME: &str = "bot-main-audio";
const STREAM_TIMING_VERSION: u32 = 1;
const STREAM_TIMING_FIRST_SEGMENT: u64 = 1;
const STREAM_TIMING_FIRST_CHUNK: u64 = 1;
const STREAM_TIMING_MAX_ELAPSED_MS: u64 = 5_000;
const STREAM_TIMING_SOURCE: &str = "stream_anchor_monotonic";
#[tokio::main(flavor = "multi_thread")]
async fn main() -> Result<()> {
@@ -660,6 +666,31 @@
        "reasonCode": reason_code,
        "retryable": retryable,
        "extension": extension,
    });
    println!("{payload}");
}
fn emit_anchored_activity(
    call_id: &str,
    trace_id: &str,
    turn_id: &str,
    event_name: &str,
    marker: &RuntimeTurnStreamTimingMarker,
    extension: serde_json::Value,
) {
    let payload = json!({
        "type": "cv_activity",
        "callId": call_id,
        "traceId": trace_id,
        "turnId": turn_id,
        "eventName": event_name,
        "eventWallTimeMs": current_time_millis(),
        "serverDeltaMs": marker.server_delta_ms,
        "serverDeltaSource": STREAM_TIMING_SOURCE,
        "result": "ok",
        "reasonCode": null,
        "retryable": null,
        "extension": marker.extension_with(extension),
    });
    println!("{payload}");
}
@@ -1420,6 +1451,7 @@
            .await?;
        }
    }
    state.close_timing();
    if !state.completed {
        warn!(
            call_id = %call_id,
@@ -1549,6 +1581,7 @@
                call_id,
                trace_id,
                turn,
                &event,
                audio_chunk,
                state,
                turn_pipeline_started_at,
@@ -1567,6 +1600,7 @@
        }
        Some("turn_completed") => {
            state.completed = true;
            state.close_timing();
            info!(
                call_id = %call_id,
                trace_id = %trace_id,
@@ -1577,6 +1611,7 @@
            );
        }
        Some("turn_failed") => {
            state.close_timing();
            let error = event.error.as_ref();
            let reason_code = error
                .and_then(|value| value.reason_code.as_deref())
@@ -1611,6 +1646,7 @@
        }
        Some("turn_cancelled") => {
            state.completed = true;
            state.close_timing();
            info!(
                call_id = %call_id,
                trace_id = %trace_id,
@@ -1643,6 +1679,19 @@
        }
        Some("activity") => {
            if let Some(activity) = event.activity.as_ref() {
                if activity.event_type.as_deref() == Some("tts_first_audio_chunk_ready") {
                    if let Some(runtime_session_nonce) =
                        bridge_config.runtime_session_nonce.as_deref()
                    {
                        let _ = state.arm_timing_anchor(
                            call_id,
                            trace_id,
                            &turn.turn_id,
                            runtime_session_nonce,
                            &event,
                        );
                    }
                }
                info!(
                    call_id = %call_id,
                    trace_id = %trace_id,
@@ -1701,6 +1750,7 @@
    call_id: &str,
    trace_id: &str,
    turn: &FinishedSpeechTurn,
    event: &RuntimeTurnStreamEvent,
    audio_chunk: &RuntimeTurnStreamAudioChunk,
    state: &mut RuntimeTurnStreamState,
    turn_pipeline_started_at: Instant,
@@ -1724,7 +1774,26 @@
        return Err(anyhow!("unsupported reply_audio_chunk format {format}"));
    }
    match state.reply_chunk_markers.observe(audio_chunk.segment_seq) {
        ReplyChunkMarker::FirstReply => emit_activity(
        ReplyChunkMarker::FirstReply => {
            let extension = json!({
                "segmentSeq": audio_chunk.segment_seq,
                "chunkSeq": audio_chunk.chunk_seq,
                "format": format.as_str(),
                "bytes": payload.len(),
            });
            if let Some(marker) =
                state.record_m6(call_id, trace_id, &turn.turn_id, event, audio_chunk)
            {
                emit_anchored_activity(
                    call_id,
                    trace_id,
                    &turn.turn_id,
                    "helper_first_reply_audio_chunk_received",
                    &marker,
                    extension,
                );
            } else {
                emit_activity(
            call_id,
            trace_id,
            Some(&turn.turn_id),
@@ -1732,13 +1801,10 @@
            "ok",
            None,
            None,
            json!({
                "segmentSeq": audio_chunk.segment_seq,
                "chunkSeq": audio_chunk.chunk_seq,
                "format": format.as_str(),
                "bytes": payload.len(),
            }),
        ),
                    extension,
                );
            }
        }
        ReplyChunkMarker::SegmentFirst => emit_activity(
            call_id,
            trace_id,
@@ -1875,6 +1941,22 @@
        sink.write_pcm_frame(frame).await?;
        if !state.first_audio_frame_written {
            state.first_audio_frame_written = true;
            let extension = json!({
                "replyPlaybackMode": state.reply_playback_mode.as_str(),
                "format": format.as_str(),
                "chunkSeq": audio_chunk.chunk_seq,
                "replyTotalAfterVadEndMs": turn_pipeline_started_at.elapsed().as_millis() as u64,
            });
            if let Some(marker) = state.record_m7() {
                emit_anchored_activity(
                    call_id,
                    trace_id,
                    &turn.turn_id,
                    "bot_reply_first_audio_frame_written",
                    &marker,
                    extension,
                );
            } else {
            emit_activity(
                call_id,
                trace_id,
@@ -1883,13 +1965,9 @@
                "ok",
                None,
                None,
                json!({
                    "replyPlaybackMode": state.reply_playback_mode.as_str(),
                    "format": format.as_str(),
                    "chunkSeq": audio_chunk.chunk_seq,
                    "replyTotalAfterVadEndMs": turn_pipeline_started_at.elapsed().as_millis() as u64,
                }),
                    extension,
            );
            }
        }
        sleep_until(pacing_started_at + Duration::from_millis(((index + 1) as u64) * 20)).await;
    }
@@ -2347,6 +2425,7 @@
    pcm_stream_decoder: Option<audio::PcmS16leStreamDecoder>,
    pcm_stream_network_chunk_count: u64,
    reply_chunk_markers: ReplyChunkMarkerState,
    timing: RuntimeTurnStreamTimingState,
}
impl Default for RuntimeTurnStreamState {
@@ -2363,8 +2442,233 @@
            pcm_stream_decoder: None,
            pcm_stream_network_chunk_count: 0,
            reply_chunk_markers: ReplyChunkMarkerState::default(),
            timing: RuntimeTurnStreamTimingState::default(),
        }
    }
}
impl RuntimeTurnStreamState {
    fn arm_timing_anchor(
        &mut self,
        call_id: &str,
        trace_id: &str,
        turn_id: &str,
        runtime_session_nonce: &str,
        event: &RuntimeTurnStreamEvent,
    ) -> bool {
        if self.timing.phase != RuntimeTurnStreamTimingPhase::Empty
            || event.call_id.as_deref() != Some(call_id)
            || event.trace_id.as_deref() != Some(trace_id)
            || event.turn_id.as_deref() != Some(turn_id)
        {
            return false;
        }
        let Some(activity) = event.activity.as_ref() else {
            return false;
        };
        if activity.event_type.as_deref() != Some("tts_first_audio_chunk_ready") {
            return false;
        }
        let Some(extension) = activity.extension.as_ref() else {
            return false;
        };
        let Some(anchor_id) = extension.stream_anchor_id.as_deref() else {
            return false;
        };
        let valid_anchor_id = (16..=64).contains(&anchor_id.len()) && anchor_id.is_ascii();
        let expected_nonce_hash = runtime_session_nonce_hash(runtime_session_nonce);
        if extension.stream_timing_version != Some(STREAM_TIMING_VERSION)
            || !valid_anchor_id
            || extension.runtime_session_nonce_hash.as_deref() != Some(expected_nonce_hash.as_str())
            || extension.segment_seq != Some(STREAM_TIMING_FIRST_SEGMENT)
            || extension.stream_timing_validation.as_deref() != Some("bound")
        {
            return false;
        }
        let Some(server_delta_ms) = extension.stream_anchor_server_delta_ms else {
            return false;
        };
        self.timing.anchor = Some(RuntimeTurnStreamTimingAnchor {
            call_id: call_id.to_string(),
            trace_id: trace_id.to_string(),
            turn_id: turn_id.to_string(),
            anchor_id: anchor_id.to_string(),
            server_delta_ms,
            runtime_session_nonce_hash: expected_nonce_hash,
            segment_seq: STREAM_TIMING_FIRST_SEGMENT,
            received_at: Instant::now(),
        });
        self.timing.phase = RuntimeTurnStreamTimingPhase::Armed;
        true
    }
    fn record_m6(
        &mut self,
        call_id: &str,
        trace_id: &str,
        turn_id: &str,
        event: &RuntimeTurnStreamEvent,
        audio_chunk: &RuntimeTurnStreamAudioChunk,
    ) -> Option<RuntimeTurnStreamTimingMarker> {
        if self.timing.phase != RuntimeTurnStreamTimingPhase::Armed {
            return None;
        }
        let anchor = self.timing.anchor.as_ref()?;
        if anchor.call_id != call_id
            || anchor.trace_id != trace_id
            || anchor.turn_id != turn_id
            || event.call_id.as_deref() != Some(call_id)
            || event.trace_id.as_deref() != Some(trace_id)
            || event.turn_id.as_deref() != Some(turn_id)
            || audio_chunk.segment_seq != Some(anchor.segment_seq)
            || audio_chunk.chunk_seq != Some(STREAM_TIMING_FIRST_CHUNK)
            || audio_chunk.stream_timing_version != Some(STREAM_TIMING_VERSION)
            || audio_chunk.stream_anchor_id.as_deref() != Some(anchor.anchor_id.as_str())
        {
            return None;
        }
        let Some(marker) = RuntimeTurnStreamTimingMarker::from_anchor(
            anchor,
            audio_chunk.chunk_seq.unwrap_or(STREAM_TIMING_FIRST_CHUNK),
        ) else {
            self.close_timing();
            return None;
        };
        self.timing.chunk_seq = Some(marker.chunk_seq);
        self.timing.phase = RuntimeTurnStreamTimingPhase::M6Recorded;
        Some(marker)
    }
    fn record_m7(&mut self) -> Option<RuntimeTurnStreamTimingMarker> {
        if self.timing.phase != RuntimeTurnStreamTimingPhase::M6Recorded {
            return None;
        }
        let anchor = self.timing.anchor.as_ref()?;
        let Some(marker) = RuntimeTurnStreamTimingMarker::from_anchor(
            anchor,
            self.timing.chunk_seq.unwrap_or(STREAM_TIMING_FIRST_CHUNK),
        ) else {
            self.close_timing();
            return None;
        };
        self.timing.phase = RuntimeTurnStreamTimingPhase::M7Recorded;
        Some(marker)
    }
    fn close_timing(&mut self) {
        self.timing.close();
    }
}
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
enum RuntimeTurnStreamTimingPhase {
    Empty,
    Armed,
    M6Recorded,
    M7Recorded,
    Closed,
}
struct RuntimeTurnStreamTimingState {
    phase: RuntimeTurnStreamTimingPhase,
    anchor: Option<RuntimeTurnStreamTimingAnchor>,
    chunk_seq: Option<u64>,
}
impl Default for RuntimeTurnStreamTimingState {
    fn default() -> Self {
        Self {
            phase: RuntimeTurnStreamTimingPhase::Empty,
            anchor: None,
            chunk_seq: None,
        }
    }
}
impl RuntimeTurnStreamTimingState {
    fn close(&mut self) {
        self.anchor = None;
        self.chunk_seq = None;
        self.phase = RuntimeTurnStreamTimingPhase::Closed;
    }
}
impl Drop for RuntimeTurnStreamTimingState {
    fn drop(&mut self) {
        self.anchor = None;
        self.chunk_seq = None;
    }
}
struct RuntimeTurnStreamTimingAnchor {
    call_id: String,
    trace_id: String,
    turn_id: String,
    anchor_id: String,
    server_delta_ms: u64,
    runtime_session_nonce_hash: String,
    segment_seq: u64,
    received_at: Instant,
}
struct RuntimeTurnStreamTimingMarker {
    version: u32,
    anchor_id: String,
    anchor_server_delta_ms: u64,
    anchor_elapsed_ms: u64,
    server_delta_ms: u64,
    runtime_session_nonce_hash: String,
    segment_seq: u64,
    chunk_seq: u64,
}
impl RuntimeTurnStreamTimingMarker {
    fn from_anchor(anchor: &RuntimeTurnStreamTimingAnchor, chunk_seq: u64) -> Option<Self> {
        let elapsed_ms = u64::try_from(anchor.received_at.elapsed().as_millis()).ok()?;
        if elapsed_ms > STREAM_TIMING_MAX_ELAPSED_MS {
            return None;
        }
        Some(Self {
            version: STREAM_TIMING_VERSION,
            anchor_id: anchor.anchor_id.clone(),
            anchor_server_delta_ms: anchor.server_delta_ms,
            anchor_elapsed_ms: elapsed_ms,
            server_delta_ms: anchor.server_delta_ms.checked_add(elapsed_ms)?,
            runtime_session_nonce_hash: anchor.runtime_session_nonce_hash.clone(),
            segment_seq: anchor.segment_seq,
            chunk_seq,
        })
    }
    fn extension_with(&self, extra: serde_json::Value) -> serde_json::Value {
        let mut extension = match extra {
            serde_json::Value::Object(value) => value,
            _ => serde_json::Map::new(),
        };
        extension.insert("streamTimingVersion".to_string(), json!(self.version));
        extension.insert("streamAnchorId".to_string(), json!(self.anchor_id));
        extension.insert(
            "streamAnchorServerDeltaMs".to_string(),
            json!(self.anchor_server_delta_ms),
        );
        extension.insert("anchorElapsedMs".to_string(), json!(self.anchor_elapsed_ms));
        extension.insert(
            "runtimeSessionNonceHash".to_string(),
            json!(self.runtime_session_nonce_hash),
        );
        extension.insert("segmentSeq".to_string(), json!(self.segment_seq));
        extension.insert("chunkSeq".to_string(), json!(self.chunk_seq));
        extension.insert("streamTimingValidation".to_string(), json!("bound"));
        serde_json::Value::Object(extension)
    }
}
fn runtime_session_nonce_hash(value: &str) -> String {
    let digest = Sha256::digest(value.as_bytes());
    digest[..6]
        .iter()
        .map(|byte| format!("{byte:02x}"))
        .collect()
}
#[derive(Debug, PartialEq, Eq)]
@@ -2412,6 +2716,12 @@
struct RuntimeTurnStreamEvent {
    #[serde(rename = "type", alias = "event")]
    event_type: Option<String>,
    #[serde(rename = "callId")]
    call_id: Option<String>,
    #[serde(rename = "traceId")]
    trace_id: Option<String>,
    #[serde(rename = "turnId")]
    turn_id: Option<String>,
    #[serde(rename = "seq")]
    seq: Option<u64>,
    #[serde(rename = "replyPlaybackMode")]
@@ -2449,6 +2759,10 @@
    chunk_seq: Option<u64>,
    #[serde(rename = "segmentSeq")]
    segment_seq: Option<u64>,
    #[serde(rename = "streamTimingVersion")]
    stream_timing_version: Option<u32>,
    #[serde(rename = "streamAnchorId")]
    stream_anchor_id: Option<String>,
    format: Option<String>,
    #[serde(rename = "sampleRate")]
    sample_rate: Option<u32>,
@@ -2465,6 +2779,23 @@
    stage: Option<String>,
    #[serde(rename = "reasonCode")]
    reason_code: Option<String>,
    extension: Option<RuntimeTurnStreamTimingExtension>,
}
#[derive(Clone, Deserialize)]
struct RuntimeTurnStreamTimingExtension {
    #[serde(rename = "streamTimingVersion")]
    stream_timing_version: Option<u32>,
    #[serde(rename = "streamAnchorId")]
    stream_anchor_id: Option<String>,
    #[serde(rename = "streamAnchorServerDeltaMs")]
    stream_anchor_server_delta_ms: Option<u64>,
    #[serde(rename = "runtimeSessionNonceHash")]
    runtime_session_nonce_hash: Option<String>,
    #[serde(rename = "segmentSeq")]
    segment_seq: Option<u64>,
    #[serde(rename = "streamTimingValidation")]
    stream_timing_validation: Option<String>,
}
#[derive(Deserialize)]
@@ -3562,7 +3893,10 @@
#[cfg(test)]
mod tests {
    use super::{ReplyChunkMarker, ReplyChunkMarkerState, RuntimeTurnStreamEvent};
    use super::{
        ReplyChunkMarker, ReplyChunkMarkerState, RuntimeTurnStreamEvent, RuntimeTurnStreamState,
        RuntimeTurnStreamTimingPhase, runtime_session_nonce_hash,
    };
    #[test]
    fn reply_chunk_marker_state_emits_turn_first_once_and_later_segment_first_once() {
@@ -3595,4 +3929,68 @@
            event.audio_chunk.and_then(|chunk| chunk.segment_seq)
        );
    }
    #[test]
    fn runtime_turn_stream_reads_frozen_m5_and_audio_chunk_timing_contract() {
        let activity: RuntimeTurnStreamEvent = serde_json::from_str(
            r#"{"type":"activity","callId":"call-1","traceId":"trace-1","turnId":"turn-1","activity":{"eventType":"tts_first_audio_chunk_ready","extension":{"streamTimingVersion":1,"streamAnchorId":"0123456789abcdef","streamAnchorServerDeltaMs":1200,"runtimeSessionNonceHash":"abcdef012345","segmentSeq":1,"streamTimingValidation":"bound"}}}"#,
        )
        .expect("m5 activity event");
        let audio: RuntimeTurnStreamEvent = serde_json::from_str(
            r#"{"type":"reply_audio_chunk","callId":"call-1","traceId":"trace-1","turnId":"turn-1","audioChunk":{"chunkSeq":1,"segmentSeq":1,"streamTimingVersion":1,"streamAnchorId":"0123456789abcdef","format":"pcm_s16le","payloadBase64":"AA==","last":false}}"#,
        )
        .expect("timed audio chunk event");
        assert_eq!(Some("call-1"), activity.call_id.as_deref());
        assert_eq!(Some("trace-1"), activity.trace_id.as_deref());
        assert_eq!(Some("turn-1"), activity.turn_id.as_deref());
        let extension = activity.activity.unwrap().extension.unwrap();
        assert_eq!(Some(1), extension.stream_timing_version);
        assert_eq!(Some(1200), extension.stream_anchor_server_delta_ms);
        assert_eq!(
            Some("0123456789abcdef"),
            audio.audio_chunk.unwrap().stream_anchor_id.as_deref()
        );
    }
    #[test]
    fn runtime_turn_stream_timing_records_m6_and_m7_once_then_rejects_terminal_late_events() {
        let nonce = "runtime-nonce";
        let nonce_hash = runtime_session_nonce_hash(nonce);
        let activity: RuntimeTurnStreamEvent = serde_json::from_str(&format!(
            r#"{{"type":"activity","callId":"call-1","traceId":"trace-1","turnId":"turn-1","activity":{{"eventType":"tts_first_audio_chunk_ready","extension":{{"streamTimingVersion":1,"streamAnchorId":"0123456789abcdef","streamAnchorServerDeltaMs":1200,"runtimeSessionNonceHash":"{nonce_hash}","segmentSeq":1,"streamTimingValidation":"bound"}}}}}}"#,
        ))
        .expect("m5 activity event");
        let audio: RuntimeTurnStreamEvent = serde_json::from_str(
            r#"{"type":"reply_audio_chunk","callId":"call-1","traceId":"trace-1","turnId":"turn-1","audioChunk":{"chunkSeq":1,"segmentSeq":1,"streamTimingVersion":1,"streamAnchorId":"0123456789abcdef","format":"pcm_s16le","payloadBase64":"AA==","last":false}}"#,
        )
        .expect("timed audio chunk event");
        let mut state = RuntimeTurnStreamState::default();
        assert!(state.arm_timing_anchor("call-1", "trace-1", "turn-1", nonce, &activity));
        let chunk = audio.audio_chunk.as_ref().expect("audio chunk");
        assert!(
            state
                .record_m6("call-1", "trace-1", "turn-1", &audio, chunk)
                .is_some()
        );
        assert!(
            state
                .record_m6("call-1", "trace-1", "turn-1", &audio, chunk)
                .is_none()
        );
        assert!(state.record_m7().is_some());
        assert!(state.record_m7().is_none());
        state.close_timing();
        assert_eq!(RuntimeTurnStreamTimingPhase::Closed, state.timing.phase);
        assert!(state.timing.anchor.is_none());
        assert!(!state.arm_timing_anchor("call-1", "trace-1", "turn-1", nonce, &activity));
        assert!(
            state
                .record_m6("call-1", "trace-1", "turn-1", &audio, chunk)
                .is_none()
        );
        assert!(state.record_m7().is_none());
    }
}
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,17 +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: start_req
            .event_callback
            .as_ref()
            .and_then(|value| value.url.clone())
            .filter(|value| !value.trim().is_empty()),
        event_callback_token: Some(profile.event_callback_token.clone()),
        event_callback_url,
        event_callback_token,
        event_callback_sender,
        status: "STARTING".to_string(),
        bot_participant_joined: false,
        bot_track_ready: false,
@@ -340,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);
@@ -348,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)
@@ -482,16 +495,35 @@
        .and_then(Value::as_str)
        .unwrap_or("worker_event");
    let result = value.get("result").and_then(Value::as_str).unwrap_or("ok");
    let callback = {
    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 = build_event_callback_dispatch(session, value);
        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;
@@ -512,10 +544,19 @@
                _ => {}
            }
        }
        callback
        if terminal && turn_id == session.active_turn_id.as_deref() {
            session.active_turn_id = None;
        }
        callback.zip(callback_sender)
    };
    if let Some(callback) = callback {
        dispatch_event_callback(callback);
    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"
            );
        }
    }
}
@@ -543,23 +584,55 @@
    })
}
fn dispatch_event_callback(callback: EventCallbackDispatch) {
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();
        match post_event_callback(&callback) {
    let max_attempts = if is_anchored_callback(&callback.payload) {
        ANCHORED_CALLBACK_MAX_ATTEMPTS
    } else {
        1
    };
    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!(
@@ -567,6 +640,7 @@
                    trace_id = ?callback.trace_id,
                    event_name = %event_name,
                    status = status,
                    attempt = attempt,
                    "helper event callback rejected"
                );
            }
@@ -575,12 +649,62 @@
                    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);
        }
    }
}
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> {
@@ -913,6 +1037,7 @@
    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,
@@ -1115,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()
        );
    }
}