fix(live-atc): stop ATC from repeating/looping and hanging on silent frequencies

- Neutralize the local engine's autonomous auto-advance (evaluateAutoTransitions/
  evaluateSimpleAutoFlow) — the Python backend now drives state exclusively via
  moveToSilent; the old walker could self-answer pilot states and race the
  backend, producing loops.
- Dedupe applyBackendDecision's ATC log entry + TTS: moveToSilent no longer logs
  say_tpl for backend-driven auto-advanced states (suppressSay), and a
  lastAppliedSay guard drops a repeated decision from overlapping sources
  (transmit reply, telemetry tick, silence timeout).
- Cap consecutive silence-timeout re-fires on the same state at 2 instead of
  re-arming forever.
- Pause telemetry forwarding while a pilot transmission is in flight, and guard
  against overlapping telemetry POSTs.
- Add request timeouts to TTS (20s) and backend transmit/telemetry/timeout
  (30s)/createSession (60s) calls so a hung request can no longer freeze the
  whole session.

Verified live against the Python backend: a full clearance→taxi chain now logs
each ATC line exactly once instead of 2-3x.
This commit is contained in:
itsrubberduck
2026-07-16 23:47:52 +02:00
parent 3c284716bb
commit 3fe431ea47
6 changed files with 139 additions and 22 deletions

View File

@@ -107,6 +107,14 @@ export function useLiveAtcSession(
// applyBackendDecision. // applyBackendDecision.
let silenceTimer: ReturnType<typeof setTimeout> | null = null let silenceTimer: ReturnType<typeof setTimeout> | null = null
// Consecutive silence-timeouts fired for the SAME state. If the backend keeps
// re-prompting the identical auto_advance_on_silence state (e.g. it re-asks the
// same read-back-less confirmation every timeout window), re-arming forever
// reads as ATC repeating itself on a loop. Reset on any pilot transmission or
// once the decision actually lands on a different state.
let silenceFireCount: { stateId: string | null; count: number } = { stateId: null, count: 0 }
const MAX_CONSECUTIVE_SILENCE_FIRES = 2
function clearSilenceTimer() { function clearSilenceTimer() {
if (silenceTimer) { if (silenceTimer) {
clearTimeout(silenceTimer) clearTimeout(silenceTimer)
@@ -114,10 +122,23 @@ export function useLiveAtcSession(
} }
} }
function resetSilenceFireCount() {
silenceFireCount = { stateId: null, count: 0 }
}
function armSilenceTimer() { function armSilenceTimer() {
clearSilenceTimer() clearSilenceTimer()
const state = currentState.value as any const state = currentState.value as any
if (!state?.auto_advance_on_silence || !backendSessionId.value) return if (!state?.auto_advance_on_silence || !backendSessionId.value) return
if (silenceFireCount.stateId !== state.id) {
silenceFireCount = { stateId: state.id, count: 0 }
}
if (silenceFireCount.count >= MAX_CONSECUTIVE_SILENCE_FIRES) {
pmLog.warn('SILENCE TIMER not re-armed — state fired', silenceFireCount.count, 'times already:', state.id)
return
}
const ms = Math.max(1000, Number(state.auto_advance_timeout_ms ?? 30000)) const ms = Math.max(1000, Number(state.auto_advance_timeout_ms ?? 30000))
const sessionAtArm = backendSessionId.value const sessionAtArm = backendSessionId.value
const stateAtArm = state.id const stateAtArm = state.id
@@ -134,6 +155,10 @@ export function useLiveAtcSession(
} }
try { try {
pmLog.info('SILENCE TIMEOUT fired →', stateAtArm) pmLog.info('SILENCE TIMEOUT fired →', stateAtArm)
silenceFireCount = {
stateId: stateAtArm,
count: (silenceFireCount.stateId === stateAtArm ? silenceFireCount.count : 0) + 1,
}
const response = await radioBackend.timeout(sessionAtArm) const response = await radioBackend.timeout(sessionAtArm)
applyBackendDecision(response) applyBackendDecision(response)
} catch (e: any) { } catch (e: any) {
@@ -145,6 +170,15 @@ export function useLiveAtcSession(
silenceTimer = setTimeout(fire, ms) silenceTimer = setTimeout(fire, ms)
} }
// Guards the ATC reply (log entry + TTS) against being applied twice for the
// same decision — applyBackendDecision can be reached from four sources
// (transmit reply, telemetry tick, silence timeout, bug-report restore) and
// two of them can legitimately fire back-to-back for the same outcome (e.g.
// a silence timeout racing an in-flight transmit reply), which otherwise
// spoke/logged the same confirmation 2-3x (design doc WP1 Fix 2).
let lastAppliedSay: { text: string; stateId: string; atMs: number } | null = null
const APPLIED_SAY_DEDUPE_MS = 15_000
// Apply a backend decision (from a pilot transmission, a telemetry tick, or a // Apply a backend decision (from a pilot transmission, a telemetry tick, or a
// silence timeout) to the local engine + UI: sync the // silence timeout) to the local engine + UI: sync the
// flow/cursor/variables/flags, speak the controller reply, and surface // flow/cursor/variables/flags, speak the controller reply, and surface
@@ -166,14 +200,18 @@ export function useLiveAtcSession(
} }
// Advance local cursor through every state the backend auto-walked, then the // Advance local cursor through every state the backend auto-walked, then the
// final state. moveToSilent updates current_unit, actions, handoffs and the // final state. moveToSilent updates current_unit, actions and handoffs
// communication log without scheduling further auto-transitions. // without scheduling further auto-transitions. suppressSay: the ATC line for
// this decision is logged exactly once below, from the backend-rendered
// sayText — logging each walked state's own say_tpl too would duplicate it
// (2-3x on chained flows with multiple auto-advanced ATC/system states).
// TTS is unaffected either way: only scheduleControllerSpeech below plays audio.
for (const stateId of response.auto_advanced_states ?? []) { for (const stateId of response.auto_advanced_states ?? []) {
pmLog.debug('moveToSilent ← auto_advanced:', stateId) pmLog.debug('moveToSilent ← auto_advanced:', stateId)
moveToSilent(stateId) moveToSilent(stateId, { suppressSay: true })
} }
pmLog.debug('moveToSilent ← next_state_id:', response.next_state_id) pmLog.debug('moveToSilent ← next_state_id:', response.next_state_id)
moveToSilent(response.next_state_id) moveToSilent(response.next_state_id, { suppressSay: true })
// Capture the per-field readback diagnostic for the STT debug panel. // Capture the per-field readback diagnostic for the STT debug panel.
lastReadbackReport.value = response.readback_report ?? [] lastReadbackReport.value = response.readback_report ?? []
@@ -201,13 +239,23 @@ export function useLiveAtcSession(
sayText = `Readback correct. ${sayText}` sayText = `Readback correct. ${sayText}`
} }
if (sayText) { if (sayText) {
pmLog.info('TTS →', sayText) const isDuplicate =
lastControllerSay.value = sayText lastAppliedSay
scheduleControllerSpeech(sayText) && lastAppliedSay.text === sayText
appendLogEntry('atc', sayText, response.next_state_id, { && lastAppliedSay.stateId === response.next_state_id
flow: response.active_flow, && Date.now() - lastAppliedSay.atMs < APPLIED_SAY_DEDUPE_MS
frequency: frequencies.value.active, if (isDuplicate) {
}) pmLog.info('TTS SKIPPED (duplicate of last-applied decision) →', sayText)
} else {
pmLog.info('TTS →', sayText)
lastControllerSay.value = sayText
scheduleControllerSpeech(sayText)
appendLogEntry('atc', sayText, response.next_state_id, {
flow: response.active_flow,
frequency: frequencies.value.active,
})
lastAppliedSay = { text: sayText, stateId: response.next_state_id, atMs: Date.now() }
}
} }
if (response.fallback_used) { if (response.fallback_used) {
@@ -393,9 +441,11 @@ export function useLiveAtcSession(
transmitInFlightCount.value++ transmitInFlightCount.value++
try { try {
// The pilot spoke — a pending silence auto-advance no longer applies. The // The pilot spoke — a pending silence auto-advance no longer applies, and
// response re-arms it if the next state also allows silence. // a live transmission means the loop-guard's job is done for this state.
// The response re-arms it (fresh count) if the next state also allows silence.
clearSilenceTimer() clearSilenceTimer()
resetSilenceFireCount()
const response = await radioBackend.transmit(backendSessionId.value, transcript) const response = await radioBackend.transmit(backendSessionId.value, transcript)
// Drop a stale reply if the pilot already transmitted again while this call // Drop a stale reply if the pilot already transmitted again while this call
@@ -432,9 +482,14 @@ export function useLiveAtcSession(
currentScreen.value = 'scenario' currentScreen.value = 'scenario'
return return
} }
pmLog.error('TRANSMIT FAILED', { transcript, session: backendSessionId.value, error: e }) const isTimeout =
e?.name === 'TimeoutError'
|| e?.name === 'AbortError'
|| e?.cause?.name === 'TimeoutError'
|| e?.cause?.name === 'AbortError'
pmLog.error(isTimeout ? 'TRANSMIT TIMED OUT' : 'TRANSMIT FAILED', { transcript, session: backendSessionId.value, error: e })
console.error('Backend transmission failed', e) console.error('Backend transmission failed', e)
setLastTransmission(`${prefix}: ${transcript} (backend failed)`) setLastTransmission(`${prefix}: ${transcript} (${isTimeout ? 'backend timeout' : 'backend failed'})`)
} finally { } finally {
transmitInFlightCount.value = Math.max(0, transmitInFlightCount.value - 1) transmitInFlightCount.value = Math.max(0, transmitInFlightCount.value - 1)
} }

View File

@@ -63,6 +63,12 @@ export function useRadioBackend() {
return (config.public.radioBackendUrl as string) || 'http://127.0.0.1:8000' return (config.public.radioBackendUrl as string) || 'http://127.0.0.1:8000'
} }
// Without a timeout, a hung Python-backend call never resolves — its
// `finally` (which clears transmitInFlightCount / re-arms the silence timer)
// never runs either, so the session reads as permanently stuck.
const TRANSMIT_TIMEOUT_MS = 30_000
const CREATE_SESSION_TIMEOUT_MS = 60_000 // taxi-route computation is slow
async function createSession( async function createSession(
flowSlug: string, flowSlug: string,
variables?: Record<string, any>, variables?: Record<string, any>,
@@ -84,6 +90,7 @@ export function useRadioBackend() {
aircraft_lat: aircraftPosition?.lat ?? null, aircraft_lat: aircraftPosition?.lat ?? null,
aircraft_lon: aircraftPosition?.lon ?? null, aircraft_lon: aircraftPosition?.lon ?? null,
}, },
signal: AbortSignal.timeout(CREATE_SESSION_TIMEOUT_MS),
}) })
} }
@@ -93,6 +100,7 @@ export function useRadioBackend() {
{ {
method: 'POST', method: 'POST',
body: { pilot_utterance: pilotUtterance }, body: { pilot_utterance: pilotUtterance },
signal: AbortSignal.timeout(TRANSMIT_TIMEOUT_MS),
}, },
) )
} }
@@ -111,6 +119,7 @@ export function useRadioBackend() {
{ {
method: 'POST', method: 'POST',
body: { telemetry }, body: { telemetry },
signal: AbortSignal.timeout(TRANSMIT_TIMEOUT_MS),
}, },
) )
} }
@@ -123,7 +132,7 @@ export function useRadioBackend() {
async function timeout(sessionId: string): Promise<RadioTransmitResponse> { async function timeout(sessionId: string): Promise<RadioTransmitResponse> {
return await $fetch<RadioTransmitResponse>( return await $fetch<RadioTransmitResponse>(
`${baseUrl()}/api/radio/session/${sessionId}/timeout`, `${baseUrl()}/api/radio/session/${sessionId}/timeout`,
{ method: 'POST' }, { method: 'POST', signal: AbortSignal.timeout(TRANSMIT_TIMEOUT_MS) },
) )
} }

View File

@@ -214,10 +214,16 @@ export function useRadioSpeech(
} }
} }
/** A hung /api/atc/say request would otherwise block the whole speech queue
* forever (enqueueSpeech serializes playback on one promise chain) — the
* session would read as "frozen" with a dead frequency. */
const TTS_FETCH_TIMEOUT_MS = 20_000
/** Kick off TTS generation immediately (parallel to whatever is playing). */ /** Kick off TTS generation immediately (parallel to whatever is playing). */
const fetchSpeechAudio = (prepared: PreparedSpeech, options: SpeechOptions = {}): Promise<any | null> => { const fetchSpeechAudio = (prepared: PreparedSpeech, options: SpeechOptions = {}): Promise<any | null> => {
const abort = new AbortController() const abort = new AbortController()
addPendingAbort(abort) addPendingAbort(abort)
const watchdog = setTimeout(() => abort.abort(), TTS_FETCH_TIMEOUT_MS)
return (async () => { return (async () => {
try { try {
const speed = options.speed ?? speechSpeed.value const speed = options.speed ?? speechSpeed.value
@@ -239,13 +245,14 @@ export function useRadioSpeech(
return response return response
} catch (err: any) { } catch (err: any) {
if (err?.name === 'AbortError' || abort.signal.aborted) { if (err?.name === 'AbortError' || abort.signal.aborted) {
pmLog.info('TTS cancelled (frequency change)') pmLog.info('TTS cancelled (frequency change or timeout)')
return null return null
} }
pmLog.error('TTS FAILED', err) pmLog.error('TTS FAILED', err)
console.error('TTS failed:', err) console.error('TTS failed:', err)
return null return null
} finally { } finally {
clearTimeout(watchdog)
deletePendingAbort(abort) deletePendingAbort(abort)
} }
})() })()

View File

@@ -17,6 +17,13 @@ export interface SimBridgeSyncDeps {
stopRecording: () => void stopRecording: () => void
/** A frequency-sim-control command the bridge has finished (or the server expired). */ /** A frequency-sim-control command the bridge has finished (or the server expired). */
onCommandResult: (result: SimControlCommandResult) => void onCommandResult: (result: SimControlCommandResult) => void
/**
* True while a pilot transmission is out at the backend (useLiveAtcSession).
* A telemetry-fired decision landing mid-transmit would apply on top of (or
* race) the transmit reply — double-says, conflicting cursor moves — so
* telemetry forwarding pauses until the transmission settles.
*/
transmitInFlight: Ref<boolean>
} }
/** /**
@@ -37,6 +44,7 @@ export function useSimBridgeSync(
const { const {
backendSessionId, radioBackend, applyBackendDecision, stopCurrentSpeech, backendSessionId, radioBackend, applyBackendDecision, stopCurrentSpeech,
resumePrerecIfSuspended, startRecording, stopRecording, onCommandResult, resumePrerecIfSuspended, startRecording, stopRecording, onCommandResult,
transmitInFlight,
} = deps } = deps
const bridgeToken = computed(() => { const bridgeToken = computed(() => {
@@ -62,14 +70,25 @@ export function useSimBridgeSync(
// Only forward telemetry that meaningfully changed, so idle cruise doesn't POST // Only forward telemetry that meaningfully changed, so idle cruise doesn't POST
// an identical tick every poll. Rounded so tiny jitter doesn't count as change. // an identical tick every poll. Rounded so tiny jitter doesn't count as change.
let lastSentTelemetrySig: string | null = null let lastSentTelemetrySig: string | null = null
// Guards against a second telemetry POST going out while one is still awaiting
// its response — a slow backend + the 3s poll interval could otherwise stack
// concurrent requests, each capable of firing its own (possibly conflicting) decision.
let telemetryPostInFlight = false
async function forwardTelemetryToBackend(rawTelemetry: any) { async function forwardTelemetryToBackend(rawTelemetry: any) {
if (!backendSessionId.value) return if (!backendSessionId.value) return
// A pilot transmission is awaiting its backend reply — a telemetry-fired
// decision landing in the middle of that would race/duplicate the reply
// (design doc WP1 Fix 4). Skip this tick without recording the signature,
// so the next poll (once the transmission has settled) retries it.
if (transmitInFlight.value) return
if (telemetryPostInFlight) return
const normalized = normalizeBridgeTelemetry(rawTelemetry) const normalized = normalizeBridgeTelemetry(rawTelemetry)
if (!normalized) return if (!normalized) return
const sig = telemetrySignature(normalized) const sig = telemetrySignature(normalized)
if (sig === lastSentTelemetrySig) return // nothing meaningful changed if (sig === lastSentTelemetrySig) return // nothing meaningful changed
lastSentTelemetrySig = sig lastSentTelemetrySig = sig
telemetryPostInFlight = true
try { try {
const response = await radioBackend.sendTelemetry(backendSessionId.value, normalized) const response = await radioBackend.sendTelemetry(backendSessionId.value, normalized)
if (response.telemetry_fired) { if (response.telemetry_fired) {
@@ -84,6 +103,8 @@ export function useSimBridgeSync(
} else { } else {
pmLog.warn('TELEMETRY forward failed', e) pmLog.warn('TELEMETRY forward failed', e)
} }
} finally {
telemetryPostInFlight = false
} }
} }

View File

@@ -169,7 +169,7 @@
</template> </template>
<script setup lang="ts"> <script setup lang="ts">
import { ref, onMounted, onUnmounted, watch } from 'vue' import { ref, computed, onMounted, onUnmounted, watch } from 'vue'
import { useRouter, useRoute } from 'vue-router' import { useRouter, useRoute } from 'vue-router'
import useCommunicationsEngine from "../../shared/utils/communicationsEngine"; import useCommunicationsEngine from "../../shared/utils/communicationsEngine";
import { useAuthStore } from '~/stores/auth' import { useAuthStore } from '~/stores/auth'
@@ -478,6 +478,10 @@ const applyBackendDecision = (
const handleSimControlResult = ( const handleSimControlResult = (
result: import('../../shared/utils/simControl').SimControlCommandResult, result: import('../../shared/utils/simControl').SimControlCommandResult,
) => session.handleSimControlResult(result) ) => session.handleSimControlResult(result)
// Named distinctly from the `transmitInFlight` destructured from `session` below
// (used for AI-traffic gating) — same underlying ref, just needed earlier here
// for useSimBridgeSync, which is constructed before `session` exists.
const bridgeSyncTransmitInFlight = computed(() => session.transmitInFlight.value)
const speech = useRadioSpeech(engine, freq, speechInterrupt, { const speech = useRadioSpeech(engine, freq, speechInterrupt, {
setLastTransmission, setLastTransmission,
@@ -576,6 +580,7 @@ const {
startRecording, startRecording,
stopRecording, stopRecording,
onCommandResult: handleSimControlResult, onCommandResult: handleSimControlResult,
transmitInFlight: bridgeSyncTransmitInFlight,
}) })
const session = useLiveAtcSession(engine, { const session = useLiveAtcSession(engine, {

View File

@@ -204,6 +204,17 @@ export default function useCommunicationsEngine() {
const ready = ref(false) const ready = ref(false)
const lastDecisionTrace = ref<LLMDecisionTrace | null>(null) const lastDecisionTrace = ref<LLMDecisionTrace | null>(null)
// The pre-backend engine used to walk states on its own (single-eligible-
// transition auto-advance, timed auto_transitions). /live-atc now gets state
// changes exclusively from the Python backend via moveToSilent(); this
// walker is neutralized there (never opted in) so it can't race the backend
// or self-answer pilot states. Kept (not deleted) for the flow editor/debug
// tooling that may still want it.
const autonomousAutoAdvanceEnabled = ref(false)
function setAutonomousAutoAdvance(enabled: boolean) {
autonomousAutoAdvanceEnabled.value = enabled
}
const flowSnapshots = reactive<Record<string, FlowSnapshot>>({}) const flowSnapshots = reactive<Record<string, FlowSnapshot>>({})
const states = computed<Record<string, RuntimeDecisionState>>(() => tree.value?.states ?? {}) const states = computed<Record<string, RuntimeDecisionState>>(() => tree.value?.states ?? {})
@@ -1068,8 +1079,11 @@ export default function useCommunicationsEngine() {
if (!nextId || !states.value[nextId]) break if (!nextId || !states.value[nextId]) break
// Advance to the next state (moveTo handles logging, actions, handoffs) // Advance to the next state. moveToSilent handles logging, actions and
moveTo(nextId) // handoffs but — unlike moveTo — does not itself schedule further
// auto-transitions; this walker's own while-loop is the only driver,
// so the backend (which owns state after the initial walk) never races it.
moveToSilent(nextId)
} }
return messages return messages
@@ -1162,6 +1176,7 @@ export default function useCommunicationsEngine() {
let pendingSimpleAutoTransition: { from: string; to: string } | null = null let pendingSimpleAutoTransition: { from: string; to: string } | null = null
function evaluateSimpleAutoFlow(loopGuard = 0) { function evaluateSimpleAutoFlow(loopGuard = 0) {
if (!autonomousAutoAdvanceEnabled.value) return
if (!ready.value || loopGuard > 20) return if (!ready.value || loopGuard > 20) return
if (pendingSimpleAutoTransition?.from === currentStateId.value) { if (pendingSimpleAutoTransition?.from === currentStateId.value) {
return return
@@ -1217,6 +1232,7 @@ export default function useCommunicationsEngine() {
} }
function evaluateAutoTransitions(loopGuard = 0) { function evaluateAutoTransitions(loopGuard = 0) {
if (!autonomousAutoAdvanceEnabled.value) return
if (!ready.value || loopGuard > 8) return if (!ready.value || loopGuard > 8) return
const state = currentState.value const state = currentState.value
if (!state) return if (!state) return
@@ -1301,7 +1317,7 @@ export default function useCommunicationsEngine() {
// Like moveTo but does NOT schedule auto-transitions — used when the backend // Like moveTo but does NOT schedule auto-transitions — used when the backend
// is driving state and we only need to sync the local cursor + side-effects // is driving state and we only need to sync the local cursor + side-effects
// (actions, handoffs, communication log) without the engine trying to advance further. // (actions, handoffs, communication log) without the engine trying to advance further.
function moveToSilent(stateId: string) { function moveToSilent(stateId: string, opts: { suppressSay?: boolean } = {}) {
ensureTree() ensureTree()
if (!states.value[stateId]) { if (!states.value[stateId]) {
console.warn(`[Engine] Unknown state for silent move: ${stateId}`) console.warn(`[Engine] Unknown state for silent move: ${stateId}`)
@@ -1332,7 +1348,10 @@ export default function useCommunicationsEngine() {
} }
} }
const sayTplSilent = stateSayTpl(s) // suppressSay: the caller (applyBackendDecision) already appends the
// backend-rendered say to the log itself — logging it again here would
// duplicate the ATC line for every auto-advanced/say-carrying state.
const sayTplSilent = opts.suppressSay ? null : stateSayTpl(s)
if (sayTplSilent) { if (sayTplSilent) {
speak(s.role, sayTplSilent, s.id!) speak(s.role, sayTplSilent, s.id!)
} }
@@ -1562,6 +1581,7 @@ export default function useCommunicationsEngine() {
// Flow Control // Flow Control
moveTo, moveTo,
moveToSilent, moveToSilent,
setAutonomousAutoAdvance,
// Utilities // Utilities
normalizeATCText, normalizeATCText,