diff --git a/src/bot/audioProcedure.ts b/src/bot/audioProcedure.ts index 25faafd..d37459f 100644 --- a/src/bot/audioProcedure.ts +++ b/src/bot/audioProcedure.ts @@ -94,21 +94,48 @@ export class AudioProcedure { const ttsTrack = streamDest.stream.getAudioTracks()?.[0]; if (!ttsTrack) return { replaced: 0, pcs: pcs?.length || 0, reason: 'no-tts-track' }; + // #region agent log + const diag: Record = { + ttsTrackId: ttsTrack.id, + ttsTrackEnabled: ttsTrack.enabled, + ttsTrackReadyState: ttsTrack.readyState, + ttsTrackMuted: ttsTrack.muted, + beforeSenderTrackIds: [] as string[], + afterSenderTrackIds: [] as string[], + }; + // #endregion + let replaced = 0; for (const pc of pcs) { try { const senders = pc.getSenders?.() || []; for (const sender of senders) { if (sender?.track?.kind === 'audio') { + // #region agent log + diag.beforeSenderTrackIds.push(sender.track.id); + // #endregion await sender.replaceTrack(ttsTrack); replaced++; + // #region agent log + const afterTrack = sender.track; + diag.afterSenderTrackIds.push(afterTrack?.id || 'null'); + diag.afterSenderTrackEnabled = afterTrack?.enabled; + diag.afterSenderTrackReadyState = afterTrack?.readyState; + // Force track enabled just in case + if (afterTrack && !afterTrack.enabled) { + afterTrack.enabled = true; + diag.forcedEnabled = true; + } + // #endregion } } - } catch { - // ignore per peer connection + } catch (err: any) { + // #region agent log + diag.error = String(err?.message || err); + // #endregion } } - return { replaced, pcs: pcs?.length || 0, reason: 'ok' }; + return { replaced, pcs: pcs?.length || 0, reason: 'ok', diag }; }; }); @@ -241,9 +268,33 @@ export class AudioProcedure { } return { replaced: 0, pcs: 0, reason: 'force-function-missing' }; }); + // #region agent log + const diag = senderInjectInfo?.diag || {}; this._logger.info( - `TTS sender injection: replaced=${senderInjectInfo?.replaced ?? 0}, pcs=${senderInjectInfo?.pcs ?? 0}, reason=${senderInjectInfo?.reason || 'n/a'}`, + `TTS sender injection: replaced=${senderInjectInfo?.replaced ?? 0}, pcs=${senderInjectInfo?.pcs ?? 0}, reason=${senderInjectInfo?.reason || 'n/a'} ` + + `ttsTrack=${diag.ttsTrackId || 'n/a'}(enabled=${diag.ttsTrackEnabled},state=${diag.ttsTrackReadyState},muted=${diag.ttsTrackMuted}) ` + + `beforeSenders=[${(diag.beforeSenderTrackIds || []).join(',')}] afterSenders=[${(diag.afterSenderTrackIds || []).join(',')}] ` + + `afterEnabled=${diag.afterSenderTrackEnabled} afterState=${diag.afterSenderTrackReadyState} forcedEnabled=${diag.forcedEnabled || false}`, ); + // #endregion + + // Collect WebRTC stats BEFORE playback + // #region agent log + const statsBefore = await this._page.evaluate(async () => { + const pcs = ((window as any).__audioCapturePeerConnections || []) as RTCPeerConnection[]; + let bytesSent = 0; let packetsSent = 0; + for (const pc of pcs) { + for (const s of (pc.getSenders?.() || [])) { + if (s?.track?.kind !== 'audio') continue; + try { + const stats = await s.getStats(); + stats.forEach((r: any) => { if (r.type === 'outbound-rtp' && r.kind === 'audio') { bytesSent += Number(r.bytesSent || 0); packetsSent += Number(r.packetsSent || 0); } }); + } catch {} + } + } + return { bytesSent, packetsSent }; + }); + // #endregion await this._page.evaluate(async ({ audioData, format }) => { const ctx = (window as any).__ttsAudioContext as AudioContext; @@ -293,6 +344,38 @@ export class AudioProcedure { }); }, { audioData, format }); + // Collect WebRTC stats AFTER playback + // #region agent log + const statsAfter = await this._page.evaluate(async () => { + const pcs = ((window as any).__audioCapturePeerConnections || []) as RTCPeerConnection[]; + let bytesSent = 0; let packetsSent = 0; + for (const pc of pcs) { + for (const s of (pc.getSenders?.() || [])) { + if (s?.track?.kind !== 'audio') continue; + try { + const stats = await s.getStats(); + stats.forEach((r: any) => { if (r.type === 'outbound-rtp' && r.kind === 'audio') { bytesSent += Number(r.bytesSent || 0); packetsSent += Number(r.packetsSent || 0); } }); + } catch {} + } + } + // Also check current sender track state + const senderInfo: any[] = []; + for (const pc of pcs) { + for (const s of (pc.getSenders?.() || [])) { + if (s?.track?.kind !== 'audio') continue; + senderInfo.push({ id: s.track.id, enabled: s.track.enabled, readyState: s.track.readyState, muted: s.track.muted }); + } + } + return { bytesSent, packetsSent, senderInfo }; + }); + this._logger.info( + `[Voice] WebRTC stats: before(bytes=${statsBefore.bytesSent},pkts=${statsBefore.packetsSent}) ` + + `after(bytes=${statsAfter.bytesSent},pkts=${statsAfter.packetsSent}) ` + + `delta(bytes=${statsAfter.bytesSent - statsBefore.bytesSent},pkts=${statsAfter.packetsSent - statsBefore.packetsSent}) ` + + `senders=${JSON.stringify(statsAfter.senderInfo)}`, + ); + // #endregion + this._logger.info('Audio playback completed'); } catch (error) { this._logger.error('Error playing audio:', error); diff --git a/src/bot/orchestrator.ts b/src/bot/orchestrator.ts index 39bca99..28dc1ae 100644 --- a/src/bot/orchestrator.ts +++ b/src/bot/orchestrator.ts @@ -520,11 +520,14 @@ export class BotOrchestrator { checked, dataCid: el.getAttribute('data-cid') || '', title: el.getAttribute('title') || '', + ariaLabel: el.getAttribute('aria-label') || '', tagName: el.tagName, looksMuted, }; }); - this._logger.info(`Mic state: checked=${state.checked}, data-cid="${state.dataCid}", tag=${state.tagName}, looksMuted=${state.looksMuted}`); + // #region agent log + this._logger.info(`Mic state: checked=${state.checked}, data-cid="${state.dataCid}", tag=${state.tagName}, looksMuted=${state.looksMuted}, ariaLabel="${state.ariaLabel}", title="${state.title}"`); + // #endregion const needsClick = state.tagName === 'INPUT' ? !state.checked