refactor(app): remove debug logging from voice and UI components

This commit is contained in:
Mohamed Boudra
2026-03-13 21:07:18 +07:00
parent 80a2f8052c
commit 502dd2d2e2
28 changed files with 56 additions and 1288 deletions
+1 -239
View File
@@ -34,34 +34,10 @@ interface CuePcm {
durationMs: number;
}
interface StreamDebugState {
count: number;
totalValue: number;
maxValue: number;
startedAtMs: number;
lastAtMs: number;
maxGapMs: number;
nextLogAtMs: number;
}
interface AudioEngineTraceOptions {
traceLabel?: string;
}
let nextAudioEngineInstanceId = 1;
function getTraceStack(): string | undefined {
const stack = new Error().stack;
if (!stack) {
return undefined;
}
return stack
.split("\n")
.slice(2, 7)
.map((line) => line.trim())
.join(" | ");
}
function resamplePcm16(
pcm: Uint8Array,
fromRate: number,
@@ -118,33 +94,10 @@ function parsePcmSampleRate(mimeType: string): number | null {
return Number.isFinite(rate) && rate > 0 ? rate : null;
}
function logVoiceNative(event: string, details?: Record<string, unknown>): void {
if (details) {
console.log(`[VoiceNative] ${event}`, details);
return;
}
console.log(`[VoiceNative] ${event}`);
}
function createStreamDebugState(nowMs: number): StreamDebugState {
return {
count: 0,
totalValue: 0,
maxValue: 0,
startedAtMs: nowMs,
lastAtMs: nowMs,
maxGapMs: 0,
nextLogAtMs: nowMs + 1000,
};
}
export function createAudioEngine(
callbacks: AudioEngineCallbacks,
options?: AudioEngineTraceOptions
_options?: AudioEngineTraceOptions
): AudioEngine {
const engineId = nextAudioEngineInstanceId++;
const traceLabel = options?.traceLabel ?? "unknown";
const traceStack = getTraceStack();
const refs: {
initialized: boolean;
captureActive: boolean;
@@ -163,8 +116,6 @@ export function createAudioEngine(
timeout: ReturnType<typeof setTimeout> | null;
};
thinkingTone: CuePcm | null;
captureDebug: StreamDebugState | null;
volumeDebug: StreamDebugState | null;
destroyed: boolean;
} = {
initialized: false,
@@ -180,135 +131,36 @@ export function createAudioEngine(
timeout: null,
},
thinkingTone: null,
captureDebug: null,
volumeDebug: null,
destroyed: false,
};
logVoiceNative("engine_created", {
engineId,
traceLabel,
stack: traceStack,
});
function resetCaptureDebug(): void {
refs.captureDebug = null;
}
function resetVolumeDebug(): void {
refs.volumeDebug = null;
}
function recordCaptureChunk(byteLength: number): void {
const nowMs = Date.now();
const debug = refs.captureDebug ?? createStreamDebugState(nowMs);
const gapMs = debug.count === 0 ? 0 : nowMs - debug.lastAtMs;
debug.count += 1;
debug.totalValue += byteLength;
debug.maxValue = Math.max(debug.maxValue, byteLength);
debug.maxGapMs = Math.max(debug.maxGapMs, gapMs);
debug.lastAtMs = nowMs;
if (nowMs >= debug.nextLogAtMs) {
const elapsedMs = Math.max(1, nowMs - debug.startedAtMs);
logVoiceNative("capture_summary", {
chunks: debug.count,
totalBytes: debug.totalValue,
averageChunkBytes: Math.round(debug.totalValue / debug.count),
maxChunkBytes: debug.maxValue,
chunksPerSecond: Number(((debug.count * 1000) / elapsedMs).toFixed(1)),
maxGapMs: debug.maxGapMs,
muted: refs.muted,
});
refs.captureDebug = createStreamDebugState(nowMs);
return;
}
refs.captureDebug = debug;
}
function recordVolumeLevel(level: number): void {
const nowMs = Date.now();
const debug = refs.volumeDebug ?? createStreamDebugState(nowMs);
const gapMs = debug.count === 0 ? 0 : nowMs - debug.lastAtMs;
debug.count += 1;
debug.totalValue += level;
debug.maxValue = Math.max(debug.maxValue, level);
debug.maxGapMs = Math.max(debug.maxGapMs, gapMs);
debug.lastAtMs = nowMs;
if (nowMs >= debug.nextLogAtMs) {
const elapsedMs = Math.max(1, nowMs - debug.startedAtMs);
logVoiceNative("volume_summary", {
samples: debug.count,
averageLevel: Number((debug.totalValue / debug.count).toFixed(3)),
peakLevel: Number(debug.maxValue.toFixed(3)),
samplesPerSecond: Number(((debug.count * 1000) / elapsedMs).toFixed(1)),
maxGapMs: debug.maxGapMs,
muted: refs.muted,
});
refs.volumeDebug = createStreamDebugState(nowMs);
return;
}
refs.volumeDebug = debug;
}
const microphoneSubscription = addExpoTwoWayAudioEventListener(
"onMicrophoneData",
(event) => {
console.log("[VoiceNative] onMicrophoneData", {
engineId,
traceLabel,
captureActive: refs.captureActive,
muted: refs.muted,
bytes: event.data.byteLength,
});
if (!refs.captureActive || refs.muted) {
return;
}
recordCaptureChunk(event.data.byteLength);
callbacks.onCaptureData(event.data);
}
);
logVoiceNative("listener_added", {
engineId,
traceLabel,
event: "onMicrophoneData",
});
const volumeSubscription = addExpoTwoWayAudioEventListener(
"onInputVolumeLevelData",
(event) => {
console.log("[VoiceNative] onInputVolumeLevelData", {
engineId,
traceLabel,
captureActive: refs.captureActive,
muted: refs.muted,
level: event.data,
});
if (!refs.captureActive) {
return;
}
const level = refs.muted ? 0 : event.data;
recordVolumeLevel(level);
callbacks.onVolumeLevel(level);
}
);
logVoiceNative("listener_added", {
engineId,
traceLabel,
event: "onInputVolumeLevelData",
});
async function ensureInitialized(): Promise<void> {
if (refs.initialized) {
return;
}
logVoiceNative("initialize_start");
await initialize();
refs.initialized = true;
logVoiceNative("initialize_complete");
}
async function ensureMicrophonePermission(): Promise<void> {
@@ -330,10 +182,6 @@ export function createAudioEngine(
const pcm16k = Buffer.from(THINKING_TONE_NATIVE_PCM_BASE64, "base64");
const durationMs = THINKING_TONE_NATIVE_PCM_DURATION_MS;
refs.thinkingTone = { pcm16k, durationMs };
logVoiceNative("thinking_tone_loaded", {
bytes: pcm16k.byteLength,
durationMs,
});
return refs.thinkingTone;
}
@@ -357,13 +205,6 @@ export function createAudioEngine(
const inputRate = parsePcmSampleRate(audio.type || "") ?? 24000;
const pcm16k = resamplePcm16(pcm, inputRate, 16000);
const durationSec = pcm16k.length / 2 / 16000;
logVoiceNative("playback_start", {
inputBytes: pcm.byteLength,
outputBytes: pcm16k.byteLength,
inputRate,
durationMs: Math.round(durationSec * 1000),
queueLength: refs.queue.length,
});
playPCMData(pcm16k);
clearPlaybackTimeout();
@@ -375,9 +216,6 @@ export function createAudioEngine(
}
active.settled = true;
refs.activePlayback = null;
logVoiceNative("playback_complete", {
durationMs: Math.round(durationSec * 1000),
});
resolve(durationSec);
}, durationSec * 1000);
} catch (error) {
@@ -386,9 +224,6 @@ export function createAudioEngine(
if (active && !active.settled) {
active.settled = true;
refs.activePlayback = null;
logVoiceNative("playback_failed", {
error: error instanceof Error ? error.message : String(error),
});
reject(error instanceof Error ? error : new Error(String(error)));
}
}
@@ -401,9 +236,6 @@ export function createAudioEngine(
}
refs.processingQueue = true;
logVoiceNative("queue_drain_start", {
queueLength: refs.queue.length,
});
while (refs.queue.length > 0) {
const item = refs.queue.shift()!;
try {
@@ -414,13 +246,9 @@ export function createAudioEngine(
}
}
refs.processingQueue = false;
logVoiceNative("queue_drain_complete");
}
function stopLooping(): void {
if (refs.looping.active) {
logVoiceNative("thinking_tone_stop");
}
refs.looping.active = false;
refs.looping.token += 1;
if (refs.looping.timeout) {
@@ -438,17 +266,9 @@ export function createAudioEngine(
async destroy() {
if (refs.destroyed) {
logVoiceNative("engine_destroy_skipped", {
engineId,
traceLabel,
});
return;
}
refs.destroyed = true;
logVoiceNative("engine_destroy_start", {
engineId,
traceLabel,
});
stopLooping();
this.stop();
this.clearQueue();
@@ -458,29 +278,13 @@ export function createAudioEngine(
}
clearPlaybackTimeout();
refs.muted = false;
resetCaptureDebug();
resetVolumeDebug();
callbacks.onVolumeLevel(0);
if (refs.initialized) {
tearDown();
refs.initialized = false;
}
microphoneSubscription.remove();
logVoiceNative("listener_removed", {
engineId,
traceLabel,
event: "onMicrophoneData",
});
volumeSubscription.remove();
logVoiceNative("listener_removed", {
engineId,
traceLabel,
event: "onInputVolumeLevelData",
});
logVoiceNative("engine_destroy_complete", {
engineId,
traceLabel,
});
},
async startCapture() {
@@ -489,23 +293,12 @@ export function createAudioEngine(
}
try {
logVoiceNative("capture_start_requested");
logVoiceNative("capture_trace", {
engineId,
traceLabel,
});
await ensureMicrophonePermission();
await ensureInitialized();
toggleRecording(true);
refs.captureActive = true;
resetCaptureDebug();
resetVolumeDebug();
logVoiceNative("capture_started");
} catch (error) {
const wrapped = error instanceof Error ? error : new Error(String(error));
logVoiceNative("capture_start_failed", {
error: wrapped.message,
});
callbacks.onError?.(wrapped);
throw wrapped;
}
@@ -517,21 +310,11 @@ export function createAudioEngine(
}
refs.captureActive = false;
refs.muted = false;
resetCaptureDebug();
resetVolumeDebug();
logVoiceNative("capture_stopped");
logVoiceNative("capture_trace", {
engineId,
traceLabel,
});
callbacks.onVolumeLevel(0);
},
toggleMute() {
refs.muted = !refs.muted;
logVoiceNative("mute_toggled", {
muted: refs.muted,
});
if (refs.muted) {
callbacks.onVolumeLevel(0);
}
@@ -545,11 +328,6 @@ export function createAudioEngine(
async play(audio: AudioPlaybackSource) {
return await new Promise<number>((resolve, reject) => {
refs.queue.push({ audio, resolve, reject });
logVoiceNative("queue_enqueue", {
queueLength: refs.queue.length,
blobBytes: audio.size,
mimeType: audio.type || null,
});
if (!refs.processingQueue) {
void processQueue();
}
@@ -557,9 +335,6 @@ export function createAudioEngine(
},
stop() {
if (refs.activePlayback) {
logVoiceNative("playback_stopped");
}
stopPlayback();
clearPlaybackTimeout();
const active = refs.activePlayback;
@@ -571,11 +346,6 @@ export function createAudioEngine(
},
clearQueue() {
if (refs.queue.length > 0) {
logVoiceNative("queue_cleared", {
queueLength: refs.queue.length,
});
}
while (refs.queue.length > 0) {
refs.queue.shift()!.reject(new Error("Playback stopped"));
}
@@ -605,11 +375,6 @@ export function createAudioEngine(
durationMs: (audio.byteLength / 2 / 16000) * 1000,
}
: await ensureThinkingTone();
logVoiceNative("thinking_tone_start", {
bytes: cue.pcm16k.byteLength,
durationMs: Math.round(cue.durationMs),
gapMs: gapMs || THINKING_TONE_REPEAT_GAP_MS,
});
const loop = () => {
if (!refs.looping.active || refs.looping.token !== token) {
@@ -617,9 +382,6 @@ export function createAudioEngine(
}
resumePlayback();
playPCMData(cue.pcm16k);
logVoiceNative("thinking_tone_tick", {
durationMs: Math.round(cue.durationMs),
});
refs.looping.timeout = setTimeout(
loop,
cue.durationMs + (gapMs || THINKING_TONE_REPEAT_GAP_MS)
@@ -139,11 +139,6 @@ export class SpeechSegmenter {
}
flush(isLast: boolean): void {
console.log("[SpeechSegmenter] flush", {
isLast,
audioBufferLength: this.audioBuffer.length,
bufferedBytes: this.bufferedBytes,
});
if (this.audioBuffer.length === 0) {
this.bufferedBytes = 0;
return;
@@ -162,13 +157,6 @@ export class SpeechSegmenter {
* In non-continuous mode, chunk buffering is gated by the VAD state.
*/
pushPcmChunk(chunk: Uint8Array): void {
console.log("[SpeechSegmenter] pushPcmChunk", {
bytes: chunk.length,
speechDetectionStartMs: this.speechDetectionStartMs,
isSpeaking: this.isSpeaking,
speechConfirmed: this.speechConfirmed,
bufferedBytes: this.bufferedBytes,
});
if (chunk.length === 0) {
return;
}
@@ -198,16 +186,6 @@ export class SpeechSegmenter {
* Called with a normalized volume level (0..1). Drives VAD transitions.
*/
pushVolumeLevel(volume: number, nowMs: number): void {
console.log("[SpeechSegmenter] pushVolumeLevel", {
volume,
nowMs,
speechDetectionStartMs: this.speechDetectionStartMs,
isSpeaking: this.isSpeaking,
isDetecting: this.isDetecting,
speechConfirmed: this.speechConfirmed,
silenceStartMs: this.silenceStartMs,
confirmedDropStartMs: this.confirmedDropStartMs,
});
if (this.config.enableContinuousStreaming) {
return;
}
-108
View File
@@ -96,17 +96,6 @@ const INITIAL_TELEMETRY: VoiceRuntimeTelemetrySnapshot = {
segmentDuration: 0,
};
function logVoiceRuntime(
event: string,
details?: Record<string, unknown>
): void {
if (details) {
console.log(`[VoiceRuntime] ${event}`, details);
return;
}
console.log(`[VoiceRuntime] ${event}`);
}
function snapshotsEqual(
left: VoiceRuntimeSnapshot,
right: VoiceRuntimeSnapshot
@@ -196,15 +185,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
}
const previous = state.snapshot;
state.snapshot = next;
logVoiceRuntime("snapshot_changed", {
previousPhase: previous.phase,
phase: next.phase,
isVoiceMode: next.isVoiceMode,
isVoiceSwitching: next.isVoiceSwitching,
isMuted: next.isMuted,
activeServerId: next.activeServerId,
activeAgentId: next.activeAgentId,
});
emit();
}
@@ -294,11 +274,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
stopCue();
return;
}
logVoiceRuntime("thinking_tone_requested", {
phase: state.snapshot.phase,
isDetecting: state.telemetry.isDetecting,
isSpeaking: state.telemetry.isSpeaking,
});
deps.engine.playLooping(new Uint8Array(0), THINKING_TONE_REPEAT_GAP_MS);
}
@@ -346,12 +321,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
if (isLast) {
state.turnInProgress = true;
}
logVoiceRuntime("audio_segment_ready", {
isLast,
base64Bytes: audioData.length,
phase: state.snapshot.phase,
serverId: activeSession.adapter.serverId,
});
void activeSession.adapter
.sendVoiceAudioChunk(audioData, PCM_MIME_TYPE, isLast)
@@ -365,10 +334,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
) {
return;
}
logVoiceRuntime("audio_segment_sent", {
isLast,
serverId: activeSession.adapter.serverId,
});
patchSnapshot((prev) => ({ ...prev, phase: "waiting" }));
reconcileCue();
})
@@ -377,11 +342,9 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
});
},
onSpeechStart: () => {
logVoiceRuntime("speech_started");
stopCue();
},
onSpeechEnd: () => {
logVoiceRuntime("speech_ended");
clearSpeechInterruptTimer();
state.speechInterruptSent = false;
reconcileCue();
@@ -390,10 +353,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
const previous = state.telemetry;
patchTelemetry((prev) => ({ ...prev, isDetecting }));
if (previous.isDetecting !== isDetecting) {
logVoiceRuntime("detecting_changed", {
isDetecting,
volume: Number(state.telemetry.volume.toFixed(3)),
});
}
if (!previous.isDetecting && isDetecting) {
stopCue();
@@ -405,11 +364,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
const previous = state.telemetry;
patchTelemetry((prev) => ({ ...prev, isSpeaking }));
if (previous.isSpeaking !== isSpeaking) {
logVoiceRuntime("speaking_changed", {
isSpeaking,
phase: state.snapshot.phase,
volume: Number(state.telemetry.volume.toFixed(3)),
});
}
if (!previous.isSpeaking && isSpeaking) {
@@ -429,15 +383,8 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
return;
}
state.speechInterruptSent = true;
logVoiceRuntime("barge_in_interrupt_triggered", {
phase: state.snapshot.phase,
});
void interruptActiveTurn();
}, REALTIME_VOICE_VAD_CONFIG.interruptGracePeriodMs);
logVoiceRuntime("barge_in_interrupt_scheduled", {
gracePeriodMs: REALTIME_VOICE_VAD_CONFIG.interruptGracePeriodMs,
phase: state.snapshot.phase,
});
}
}
@@ -543,9 +490,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
},
registerSession(adapter) {
logVoiceRuntime("session_registered", {
serverId: adapter.serverId,
});
sessions.set(adapter.serverId, {
adapter,
connected: true,
@@ -566,10 +510,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
return;
}
session.connected = connected;
logVoiceRuntime("session_connection_changed", {
serverId,
connected,
});
if (state.snapshot.activeServerId !== serverId) {
return;
}
@@ -581,12 +521,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
},
handleCapturePcm(chunk) {
console.log("[VoiceRuntime] handleCapturePcm", {
bytes: chunk.byteLength,
isVoiceMode: state.snapshot.isVoiceMode,
isMuted: state.snapshot.isMuted,
phase: state.snapshot.phase,
});
if (!state.snapshot.isVoiceMode || state.snapshot.isMuted) {
return;
}
@@ -595,12 +529,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
handleCaptureVolume(level) {
const nowMs = Date.now();
console.log("[VoiceRuntime] handleCaptureVolume", {
level,
isVoiceMode: state.snapshot.isVoiceMode,
isMuted: state.snapshot.isMuted,
phase: state.snapshot.phase,
});
const displayLevel = state.snapshot.isMuted ? 0 : level;
publishDisplayVolume(displayLevel, nowMs);
if (!state.snapshot.isVoiceMode || state.snapshot.isMuted) {
@@ -610,10 +538,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
},
async startVoice(serverId, agentId) {
logVoiceRuntime("start_requested", {
serverId,
agentId,
});
const session = sessions.get(serverId);
if (!session) {
throw new Error(`Voice runtime is not ready for host ${serverId}`);
@@ -678,26 +602,13 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
phase: "listening",
isMuted: deps.engine.isMuted(),
}));
logVoiceRuntime("start_completed", {
serverId,
agentId,
});
} catch (error) {
logVoiceRuntime("start_failed", {
serverId,
agentId,
error: error instanceof Error ? error.message : String(error),
});
await performLocalStop();
throw error;
}
},
async stopVoice() {
logVoiceRuntime("stop_requested", {
activeServerId: state.snapshot.activeServerId,
activeAgentId: state.snapshot.activeAgentId,
});
const activeSession = getActiveSession();
const generation = state.generation + 1;
state.generation = generation;
@@ -722,7 +633,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
if (state.generation === generation) {
resetToDisabledState();
}
logVoiceRuntime("stop_completed");
}
},
@@ -736,9 +646,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
toggleMute() {
const nextMuted = deps.engine.toggleMute();
logVoiceRuntime("mute_toggled", {
muted: nextMuted,
});
if (nextMuted) {
resetSegmenter(segmenter);
patchSnapshot((prev) => ({
@@ -778,9 +685,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
) {
return;
}
logVoiceRuntime("assistant_audio_started", {
serverId,
});
stopCue();
getActiveSession()?.adapter.setAssistantAudioPlaying(true);
patchSnapshot((prev) => ({ ...prev, phase: "playing" }));
@@ -791,10 +695,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
return;
}
logVoiceRuntime("assistant_audio_finished", {
serverId,
turnInProgress: state.turnInProgress,
});
getActiveSession()?.adapter.setAssistantAudioPlaying(false);
if (!state.snapshot.isVoiceMode) {
return;
@@ -822,9 +722,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
return;
}
logVoiceRuntime("empty_transcription_result", {
serverId,
});
state.turnInProgress = false;
patchSnapshot((prev) => ({ ...prev, phase: "listening" }));
stopCue();
@@ -838,11 +735,6 @@ export function createVoiceRuntime(deps: VoiceRuntimeDeps): VoiceRuntime {
) {
return;
}
logVoiceRuntime("turn_event", {
serverId,
agentId,
eventType,
});
if (eventType === "turn_started") {
state.turnInProgress = true;