diff --git a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioEngine.kt b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioEngine.kt index 12e6369e..50485a64 100644 --- a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioEngine.kt +++ b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioEngine.kt @@ -40,9 +40,10 @@ class CallAudioEngine { } private val recordLock = Any() + private val trackLock = Any() private var audioRecord: AudioRecord? = null private var captureThread: Thread? = null - private var audioTrack: AudioTrack? = null + @Volatile private var audioTrack: AudioTrack? = null private var playThread: Thread? = null private var prevMode: Int = AudioManager.MODE_NORMAL private var prevSpeaker: Boolean = false @@ -52,6 +53,9 @@ class CallAudioEngine { @Volatile private var active = false @Volatile private var callId = 0L + @Volatile private var captureReady = false + @Volatile private var playReady = false + private var duplexReady = false // только main @Volatile private var muted = false @@ -73,7 +77,7 @@ class CallAudioEngine { fun isActive(): Boolean = active val diagnostics: String get() = synchronized(recordLock) { - "active=$active capture=$capFramesRead play=$playFramesWritten " + + "active=$active ready=$captureReady/$playReady capture=$capFramesRead play=$playFramesWritten " + "workers=${captureThread?.isAlive}/${playThread?.isAlive} " + "record=${audioRecord?.recordingState} track=${audioTrack?.playState} route=${router.route}" } @@ -87,7 +91,7 @@ class CallAudioEngine { fun isMuted(): Boolean = muted - /** Запустить полнодуплекс для звонка. Возвращает true при успехе. */ + /** Подготовить маршрут и запустить независимые RX/TX. Ошибки подготовки устройств приходят через onFailure. */ fun start(id: Long): Boolean { stop() startElapsedMs = SystemClock.elapsedRealtime() @@ -101,6 +105,7 @@ class CallAudioEngine { callId = id muted = false failed.set(false) + captureReady = false; playReady = false; duplexReady = false try { val ctx = ChatApplication.instance val am = ctx.getSystemService(Context.AUDIO_SERVICE) as AudioManager @@ -128,82 +133,98 @@ class CallAudioEngine { capFramesRead = 0L syncAecForRoute(router.route) - // ── AudioRecord (захват) ── wiredActive = router.route == AudioRoute.HEADSET && router.wiredInputDevice() != null wantedWired = wiredActive - stageAt = SystemClock.elapsedRealtime() - audioRecord = createAudioRecord(wiredActive) - if (audioRecord == null) { - stop(); return false - } - val recordCreateMs = SystemClock.elapsedRealtime() - stageAt - - /* Захват начинает отправку сразу; подготовка playback больше его не задерживает. */ router.onInputDevice = { _ -> wantedWired = router.route == AudioRoute.HEADSET && router.wiredInputDevice() != null } - active = true - captureElapsedMs = SystemClock.elapsedRealtime() - audioRecord?.startRecording() - if (audioRecord?.recordingState != AudioRecord.RECORDSTATE_RECORDING) { - LogManager.addLog("ERROR", "CallAudio", "capture not running id=$id record=${audioRecord?.recordingState}") - stop(); return false - } - val recordStartMs = SystemClock.elapsedRealtime() - captureElapsedMs - captureThread = Thread({ runWorker(id, "capture") { captureLoop() } }, "utun-call-capture").apply { start() } - LogManager.addLog("INFO", "CallAudio", - "capture started id=$id totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} " + - "nativeMs=$nativeMs modeMs=$modeMs routeMs=$routeMs recordCreateMs=$recordCreateMs recordStartMs=$recordStartMs") - - // ── AudioTrack (воспроизведение) ── - stageAt = SystemClock.elapsedRealtime() - val trackMin = AudioTrack.getMinBufferSize( - SAMPLE_RATE, AudioFormat.CHANNEL_OUT_MONO, AudioFormat.ENCODING_PCM_16BIT) - if (trackMin <= 0) { - LogManager.addLog("ERROR", "CallAudio", "AudioTrack.getMinBufferSize=$trackMin id=$id") - stop(); return false - } - val trackBuf = (trackMin * 2).coerceAtLeast(FRAME_SAMPLES * 4) - audioTrack = try { - AudioTrack( - AudioAttributes.Builder() - .setUsage(AudioAttributes.USAGE_VOICE_COMMUNICATION) - .setContentType(AudioAttributes.CONTENT_TYPE_SPEECH).build(), - AudioFormat.Builder().setSampleRate(SAMPLE_RATE) - .setEncoding(AudioFormat.ENCODING_PCM_16BIT) - .setChannelMask(AudioFormat.CHANNEL_OUT_MONO).build(), - trackBuf, AudioTrack.MODE_STREAM, AudioManager.AUDIO_SESSION_ID_GENERATE) - } catch (e: Exception) { - LogManager.addLog("ERROR", "CallAudio", "AudioTrack create failed: ${e.message}") - stop(); return false - } - - if (audioTrack?.state != AudioTrack.STATE_INITIALIZED) { - LogManager.addLog("ERROR", "CallAudio", "AudioTrack not initialized id=$id") - stop(); return false - } - - /* Прямое роутирование трека на выбранное устройство вывода (обход глючной - глобальной маршрутизации на ряде устройств). */ router.onOutputDevice = { dev -> applyTrackOutputDevice(dev) } - applyTrackOutputDevice(router.currentOutputDevice) - val trackCreateMs = SystemClock.elapsedRealtime() - stageAt - stageAt = SystemClock.elapsedRealtime() - audioTrack?.play() - if (audioTrack?.playState != AudioTrack.PLAYSTATE_PLAYING) { - LogManager.addLog("ERROR", "CallAudio", "playback not running id=$id track=${audioTrack?.playState}") - stop(); return false + /* Замер AEC — через 300мс после готовности обоих направлений; RX этого не ждёт. */ + val ready = Runnable { + if (callId == id && active && !failed.get() && captureReady && playReady && !duplexReady) { + duplexReady = true + mainHandler.postDelayed(aecDelayRunnable, 300) + LogManager.addLog("INFO", "CallAudio", "duplex ready id=$id totalMs=${SystemClock.elapsedRealtime() - startElapsedMs}") + } } - val trackStartMs = SystemClock.elapsedRealtime() - stageAt - playThread = Thread({ runWorker(id, "play") { playLoop() } }, "utun-call-play").apply { start() } + active = true - /* Через ~300мс буферы устройства заполнены — замеряем реальную задержку AEC. */ - mainHandler.postDelayed(aecDelayRunnable, 300) + // Каждый поток готовит только своё устройство. Отмена ждёт оба до release Android/native. + playThread = Thread({ runWorker(id, "play") { + synchronized(trackLock) { + if (!active) return@runWorker + val createdAt = SystemClock.elapsedRealtime() + val trackMin = AudioTrack.getMinBufferSize( + SAMPLE_RATE, AudioFormat.CHANNEL_OUT_MONO, AudioFormat.ENCODING_PCM_16BIT) + if (trackMin <= 0) { + reportFailure(id, "AudioTrack.getMinBufferSize=$trackMin") + return@runWorker + } + val trackBuf = (trackMin * 2).coerceAtLeast(FRAME_SAMPLES * 4) + val track = AudioTrack( + AudioAttributes.Builder().setUsage(AudioAttributes.USAGE_VOICE_COMMUNICATION) + .setContentType(AudioAttributes.CONTENT_TYPE_SPEECH).build(), + AudioFormat.Builder().setSampleRate(SAMPLE_RATE).setEncoding(AudioFormat.ENCODING_PCM_16BIT) + .setChannelMask(AudioFormat.CHANNEL_OUT_MONO).build(), + trackBuf, AudioTrack.MODE_STREAM, AudioManager.AUDIO_SESSION_ID_GENERATE) + audioTrack = track + if (!active) return@runWorker + if (track.state != AudioTrack.STATE_INITIALIZED) { + reportFailure(id, "AudioTrack not initialized state=${track.state}") + return@runWorker + } + applyTrackOutputDevice(router.currentOutputDevice) + val trackCreateMs = SystemClock.elapsedRealtime() - createdAt + val playedAt = SystemClock.elapsedRealtime() + track.play() + if (!active) return@runWorker + if (track.playState != AudioTrack.PLAYSTATE_PLAYING) { + reportFailure(id, "playback not running state=${track.playState}") + return@runWorker + } + playReady = true + LogManager.addLog("INFO", "CallAudio", + "playback started id=$id totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} " + + "trackCreateMs=$trackCreateMs trackStartMs=${SystemClock.elapsedRealtime() - playedAt} " + + "trackBuf=$trackBuf captureReady=$captureReady") + } + mainHandler.post(ready) + playLoop() + } }, "utun-call-play").apply { start() } + captureThread = Thread({ runWorker(id, "capture") { + synchronized(recordLock) { + if (!active) return@runWorker + val createdAt = SystemClock.elapsedRealtime() + wiredActive = wantedWired + val rec = createAudioRecord(wiredActive) + audioRecord = rec + if (!active) return@runWorker + if (rec == null) { + reportFailure(id, "AudioRecord create failed wired=$wiredActive") + return@runWorker + } + val recordCreateMs = SystemClock.elapsedRealtime() - createdAt + captureElapsedMs = SystemClock.elapsedRealtime() + rec.startRecording() + if (!active) return@runWorker + if (rec.recordingState != AudioRecord.RECORDSTATE_RECORDING) { + reportFailure(id, "capture not running state=${rec.recordingState}") + return@runWorker + } + captureReady = true + LogManager.addLog("INFO", "CallAudio", + "capture started id=$id totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} " + + "recordCreateMs=$recordCreateMs recordStartMs=${SystemClock.elapsedRealtime() - captureElapsedMs} " + + "playReady=$playReady") + } + mainHandler.post(ready) + captureLoop() + } }, "utun-call-capture").apply { start() } LogManager.addLog("INFO", "CallAudio", - "started id=$id totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} " + - "trackCreateMs=$trackCreateMs trackStartMs=$trackStartMs wired=$wiredActive trackBuf=$trackBuf") + "preparing RX/TX independently id=$id totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} " + + "nativeMs=$nativeMs modeMs=$modeMs routeMs=$routeMs") return true } catch (e: Exception) { LogManager.addLog("ERROR", "CallAudio", "start failed id=$id: ${e.message}") @@ -243,9 +264,11 @@ class CallAudioEngine { catch (e: Exception) { LogManager.addLog("WARN", "CallAudio", "record stop failed id=$id: ${e.message}") } } } - audioTrack?.let { track -> - try { if (track.playState == AudioTrack.PLAYSTATE_PLAYING) track.pause() } - catch (e: Exception) { LogManager.addLog("WARN", "CallAudio", "track pause failed id=$id: ${e.message}") } + synchronized(trackLock) { + audioTrack?.let { track -> + try { if (track.playState == AudioTrack.PLAYSTATE_PLAYING) track.pause() } + catch (e: Exception) { LogManager.addLog("WARN", "CallAudio", "track pause failed id=$id: ${e.message}") } + } } playThread?.interrupt() captureThread?.join(); captureThread = null @@ -258,6 +281,7 @@ class CallAudioEngine { try { audioTrack?.release() } catch (e: Exception) { LogManager.addLog("WARN", "CallAudio", "track release failed id=$id: ${e.message}") } audioTrack = null + captureReady = false; playReady = false; duplexReady = false NativeLib.callAudioStop() router.onOutputDevice = null router.onInputDevice = null @@ -298,6 +322,7 @@ class CallAudioEngine { return } var read = 0 + val readAt = if (frame == 0L) SystemClock.elapsedRealtime() else 0L while (read < FRAME_SAMPLES) { if (!active) return // stop() разблокирует read до join; обычный захват не требует polling. @@ -311,7 +336,8 @@ class CallAudioEngine { if (frame == 0L) { val now = SystemClock.elapsedRealtime() LogManager.addLog("INFO", "CallAudio", - "first capture id=$callId totalMs=${now - startElapsedMs} recordToFrameMs=${now - captureElapsedMs}") + "first capture id=$callId totalMs=${now - startElapsedMs} " + + "recordToFrameMs=${now - captureElapsedMs} readMs=${now - readAt} playReady=$playReady") } /* диагностика: уровень захваченного сигнала (тишина vs звук) */ if (sinceSwap < 10 || frame % 100L == 0L) { @@ -381,6 +407,7 @@ class CallAudioEngine { val silence = ShortArray(FRAME_SAMPLES) val frameNs = FRAME_MS * 1_000_000L var nextNs = System.nanoTime() + var firstWrite = true while (active) { val track = audioTrack ?: return val n = NativeLib.callAudioPull(callId, buf) @@ -413,6 +440,12 @@ class CallAudioEngine { } } + if (firstWrite && active) { + firstWrite = false + LogManager.addLog("INFO", "CallAudio", + "first playback write id=$callId totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} captureReady=$captureReady") + } + /* абсолютный deadline: не даём Thread.sleep накопить систематический дрейф * (важно для стабильного выравнивания рендер↔захват в AEC). */ nextNs += frameNs @@ -436,7 +469,7 @@ class CallAudioEngine { /** Замер реальной задержки рендер→захват и применение к AEC (один раз после старта). */ private fun measureAecDelay() { synchronized(recordLock) { - if (!active) return + if (!active || !captureReady || !playReady) return val track = audioTrack ?: return val rec = audioRecord ?: return try { @@ -474,13 +507,17 @@ class CallAudioEngine { } private fun applyTrackOutputDevice(dev: AudioDeviceInfo?) { - val track = audioTrack ?: return - if (dev == null) return - try { - track.setPreferredDevice(dev) - LogManager.addLog("DEBUG", "CallAudio", "track preferred device -> type=${dev.type}") - } catch (e: Exception) { - LogManager.addLog("WARN", "CallAudio", "setPreferredDevice failed: ${e.message}") + synchronized(trackLock) { + val track = audioTrack ?: return + if (!active || dev == null) return + val startedAt = SystemClock.elapsedRealtime() + try { + val ok = track.setPreferredDevice(dev) + LogManager.addLog(if (ok) "INFO" else "WARN", "CallAudio", + "track preferred device type=${dev.type} accepted=$ok totalMs=${SystemClock.elapsedRealtime() - startedAt}") + } catch (e: Exception) { + LogManager.addLog("WARN", "CallAudio", "setPreferredDevice failed: ${e.message}") + } } } } diff --git a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioRouter.kt b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioRouter.kt index 539ea360..740aecf4 100644 --- a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioRouter.kt +++ b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioRouter.kt @@ -96,20 +96,29 @@ class CallAudioRouter { override fun onAudioDevicesAdded(addedDevices: Array?) = onDevicesChanged() override fun onAudioDevicesRemoved(removedDevices: Array?) = onDevicesChanged() } + var stageAt = SystemClock.elapsedRealtime() am.registerAudioDeviceCallback(cb, Handler(Looper.getMainLooper())) deviceCallback = cb + val callbackMs = SystemClock.elapsedRealtime() - stageAt + stageAt = SystemClock.elapsedRealtime() bindBtHeadsetProfile() + val btProfileMs = SystemClock.elapsedRealtime() - stageAt val devicesAt = SystemClock.elapsedRealtime() devices = am.getDevices(AudioManager.GET_DEVICES_ALL) val devicesMs = SystemClock.elapsedRealtime() - devicesAt hasEarpiece = findBuiltinEarpiece() != null route = if (autoHeadset) (if (isHeadsetConnected()) AudioRoute.HEADSET else fallbackRoute) else preferredRoute + stageAt = SystemClock.elapsedRealtime() applyRoute(route) + val applyMs = SystemClock.elapsedRealtime() - stageAt + stageAt = SystemClock.elapsedRealtime() refresh() + val refreshMs = SystemClock.elapsedRealtime() - stageAt LogManager.addLog("INFO", "CallAudioRouter", - "started totalMs=${SystemClock.elapsedRealtime() - startedAt} devicesMs=$devicesMs " + + "started totalMs=${SystemClock.elapsedRealtime() - startedAt} callbackMs=$callbackMs btProfileMs=$btProfileMs " + + "devicesMs=$devicesMs applyMs=$applyMs refreshMs=$refreshMs " + "devices=${devices?.size} hasEarpiece=$hasEarpiece autoHeadset=$autoHeadset fallback=$fallbackRoute") } @@ -172,6 +181,7 @@ class CallAudioRouter { /* ── применение маршрута ── */ private fun applyRoute(r: AudioRoute) { + val startedAt = SystemClock.elapsedRealtime() try { var dev: AudioDeviceInfo? = null var inDev: AudioDeviceInfo? = null @@ -235,7 +245,8 @@ class CallAudioRouter { onInputDevice?.invoke(inDev) LogManager.addLog("INFO", "CallAudioRouter", "route -> $r dev=${dev?.type}/${dev?.productName ?: "-"} inDev=${inDev?.type ?: "-"} " + - "preferWired=$preferWiredHeadset mode=${am.mode} speaker=${am.isSpeakerphoneOn}") + "preferWired=$preferWiredHeadset mode=${am.mode} speaker=${am.isSpeakerphoneOn} " + + "totalMs=${SystemClock.elapsedRealtime() - startedAt}") } catch (e: Exception) { LogManager.addLog("ERROR", "CallAudioRouter", "applyRoute $r failed: ${e.message}") }