Reopen call output on confirmed routes and recompute AEC from physical latency

tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioEngine.kt

@@ -1,7 +1,6 @@
 package com.utun.chat.data
 
 import android.content.Context
-import android.media.AudioAttributes
 import android.media.AudioDeviceInfo
 import android.media.AudioFormat
 import android.media.AudioManager
@@ -45,7 +44,7 @@ class CallAudioEngine {
     private val trackLock = Any()
     private var audioRecord: AudioRecord? = null
     private var captureThread: Thread? = null
-    @Volatile private var audioTrack: AudioTrack? = null
+    @Volatile private var audioTrack: CallAudioOutput? = null
     private var playThread: Thread? = null
     private var prevMode: Int = AudioManager.MODE_NORMAL
     private var prevSpeaker: Boolean = false
@@ -72,6 +71,10 @@ class CallAudioEngine {
     @Volatile private var capFramesRead = 0L
     private var playbackBuffer: CallPlaybackBuffer? = null // под trackLock
     @Volatile private var routeGeneration = 0L
+    @Volatile private var confirmedDeviceId = 0
+    private var communicationListener: AudioManager.OnCommunicationDeviceChangedListener? = null
+    private val outputPosition = CallOutputPosition() // writer; reporter читает под trackLock
+    private var outputRecovery = CallOutputRecovery()
     private data class OutputSample(val atUs: Long, val generation: Long, val latency: CallOutputLatency)
     @Volatile private var outputSample: OutputSample? = null
     @Volatile private var startElapsedMs = 0L
@@ -80,9 +83,8 @@ class CallAudioEngine {
     private val trackRouteListener = AudioRouting.OnRoutingChangedListener { output ->
         synchronized(trackLock) {
             val track = audioTrack
-            if (active && track != null && output === track) {
-                routeGeneration++
-                configurePlaybackBuffer(track, "route")
+            if (active && track != null && output === track.track && Build.VERSION.SDK_INT < 31) {
+                confirmedDeviceId = track.routedDevice?.id ?: 0
             }
         }
     }
@@ -141,6 +143,7 @@ class CallAudioEngine {
 
         callId = id
         routeGeneration = 0; outputSample = null
+        outputRecovery = CallOutputRecovery()
         router.bindTelecom(TelecomCallManager.connectionFor(id))
         muted = false
         failed.set(false)
@@ -192,56 +195,32 @@ class CallAudioEngine {
                 }
             }
             active = true
+            confirmedDeviceId = if (Build.VERSION.SDK_INT >= 31) am.communicationDevice?.id ?: 0 else 0
+            if (Build.VERSION.SDK_INT >= 31) {
+                val listener = AudioManager.OnCommunicationDeviceChangedListener { device ->
+                    if (active && callId == id) {
+                        val next = device?.id ?: 0
+                        if (next != confirmedDeviceId) {
+                            LogManager.addLog("INFO", "CallAudio", "output route confirmed id=$id device=$next type=${device?.type}")
+                            confirmedDeviceId = next
+                        }
+                    }
+                }
+                communicationListener = listener
+                am.addOnCommunicationDeviceChangedListener(ctx.mainExecutor, listener)
+            }
 
             // Каждый поток готовит только своё устройство. Отмена ждёт оба до 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 minQueryMs = SystemClock.elapsedRealtime() - createdAt
-                    val trackBuf = (trackMin * 2).coerceAtLeast(FRAME_SAMPLES * 4)
-                    val constructorAt = SystemClock.elapsedRealtime()
-                    val track = AudioTrack.Builder()
-                        .setAudioAttributes(AudioAttributes.Builder().setUsage(AudioAttributes.USAGE_VOICE_COMMUNICATION)
-                            .setContentType(AudioAttributes.CONTENT_TYPE_SPEECH).build())
-                        .setAudioFormat(AudioFormat.Builder().setSampleRate(SAMPLE_RATE).setEncoding(AudioFormat.ENCODING_PCM_16BIT)
-                            .setChannelMask(AudioFormat.CHANNEL_OUT_MONO).build())
-                        .setBufferSizeInBytes(trackBuf).setTransferMode(AudioTrack.MODE_STREAM)
-                        .setPerformanceMode(AudioTrack.PERFORMANCE_MODE_LOW_LATENCY).build()
-                    val constructorMs = SystemClock.elapsedRealtime() - constructorAt
-                    audioTrack = track
-                    if (!active) return@runWorker
-                    if (track.state != AudioTrack.STATE_INITIALIZED) {
-                        reportFailure(id, "AudioTrack not initialized state=${track.state}")
-                        return@runWorker
-                    }
-                    val routingAt = SystemClock.elapsedRealtime()
-                    applyTrackOutputDevice(router.currentOutputDevice)
-                    val routingMs = SystemClock.elapsedRealtime() - routingAt
-                    val bufferAt = SystemClock.elapsedRealtime()
-                    configurePlaybackBuffer(track, "start")
-                    val bufferMs = SystemClock.elapsedRealtime() - bufferAt
-                    track.addOnRoutingChangedListener(trackRouteListener, mainHandler)
-                    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
-                    }
+                    outputPosition.reset()
+                    outputRecovery.route(confirmedDeviceId)
+                    openPlaybackOutput("start")
                     playReady = true
                     LogManager.addLog("INFO", "CallAudio",
                         "playback started id=$id totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} " +
-                            "trackCreateMs=$trackCreateMs trackStartMs=${SystemClock.elapsedRealtime() - playedAt} " +
-                            "minQueryMs=$minQueryMs constructorMs=$constructorMs routingMs=$routingMs bufferMs=$bufferMs " +
-                            "trackBuf=$trackBuf captureReady=$captureReady")
+                            "backend=${audioTrack?.name} captureReady=$captureReady")
                 }
                 mainHandler.post(ready)
                 playLoop()
@@ -312,6 +291,13 @@ class CallAudioEngine {
         val id = callId
         active = false
         mainHandler.removeCallbacks(aecDelayRunnable)
+        if (Build.VERSION.SDK_INT >= 31) {
+            communicationListener?.let { listener ->
+                val am = ChatApplication.instance.getSystemService(Context.AUDIO_SERVICE) as AudioManager
+                am.removeOnCommunicationDeviceChangedListener(listener)
+            }
+            communicationListener = null
+        }
         synchronized(recordLock) {
             audioRecord?.let { rec ->
                 try { if (rec.recordingState == AudioRecord.RECORDSTATE_RECORDING) rec.stop() }
@@ -495,15 +481,56 @@ class CallAudioEngine {
         return rec
     }
 
+    /** Под trackLock; единственный создатель/владелец выхода — playback worker. */
+    private fun openPlaybackOutput(reason: String) {
+        val am = ChatApplication.instance.getSystemService(Context.AUDIO_SERVICE) as AudioManager
+        val begin = SystemClock.elapsedRealtime()
+        val track = CallAudioOutput.open(am, outputRecovery.deviceId, outputRecovery.tryFast)
+        audioTrack = track
+        applyTrackOutputDevice(router.currentOutputDevice)
+        configurePlaybackBuffer(track, reason)
+        track.addOnRoutingChangedListener(trackRouteListener, mainHandler)
+        track.play()
+        check(track.playState == AudioTrack.PLAYSTATE_PLAYING) { "${track.name} not playing" }
+        LogManager.addLog("INFO", "CallAudio", "output opened id=$callId backend=${track.name} reason=$reason " +
+            "device=${outputRecovery.deviceId} generation=$routeGeneration base=${outputPosition.base} " +
+            "failures=${outputRecovery.failures} openMs=${SystemClock.elapsedRealtime() - begin}")
+    }
+
+    private fun replacePlaybackOutput(epoch: Long, reason: String) {
+        synchronized(trackLock) {
+            if (!active) return
+            CallOutputNative.suspendClock(callId, epoch)
+            routeGeneration++
+            outputSample = null
+            val old = audioTrack
+            LogManager.addLog("INFO", "CallAudio", "output replace id=$callId reason=$reason backend=${old?.name} " +
+                "written=$playFramesWritten head=$playFramesPlayed pendingFrames=${playFramesWritten - playFramesPlayed} " +
+                "device=${outputRecovery.deviceId} next=$confirmedDeviceId")
+            old?.removeOnRoutingChangedListener(trackRouteListener)
+            old?.release()
+            audioTrack = null
+            outputPosition.reopen(playFramesWritten)
+            playFramesPlayed = playFramesWritten
+            outputRecovery.route(confirmedDeviceId)
+            openPlaybackOutput(reason)
+        }
+    }
+
     private fun playLoop() {
         val trace = CallAudioTrace(callId) { level, message -> LogManager.addLog(level, "call", message) }
-        val track = audioTrack ?: return
         val reporter = Thread({
             try {
                 val stamp = AudioTimestamp()
                 while (!Thread.currentThread().isInterrupted) {
-                    if (active) adjustPlaybackBuffer(track)
-                    if (active) trace.device = samplePlaybackDevice(track, stamp)
+                    synchronized(trackLock) {
+                        audioTrack?.let { track ->
+                            if (active) {
+                                trace.device = samplePlaybackDevice(track, stamp)
+                                adjustPlaybackBuffer(track)
+                            }
+                        }
+                    }
                     trace.flush()
                     Thread.sleep(200)
                 }
@@ -530,7 +557,7 @@ class CallAudioEngine {
     }
 
     /** Только reporter: Binder/внутренние locks AudioTrack не должны вызываться здесь из playback. */
-    private fun samplePlaybackDevice(track: AudioTrack, stamp: AudioTimestamp): CallAudioTrace.DeviceSample {
+    private fun samplePlaybackDevice(track: CallAudioOutput, stamp: AudioTimestamp): CallAudioTrace.DeviceSample {
         val beginNs = System.nanoTime()
         val generation = routeGeneration
         val stampOk = track.getTimestamp(stamp)
@@ -544,7 +571,8 @@ class CallAudioEngine {
         val endNs = System.nanoTime()
         return CallAudioTrace.DeviceSample(
             route?.id?.toLong() ?: -1, route?.type?.toLong() ?: -1, underruns, bufferFrames, startFrames,
-            if (stampOk) stamp.framePosition else -1, if (stampOk) stamp.nanoTime else -1, stampOk,
+            if (stampOk) outputPosition.timestamp(stamp.framePosition, playFramesWritten) else -1,
+            if (stampOk) stamp.nanoTime else -1, stampOk,
             beginNs / 1000, endNs / 1000, (stampEndNs - beginNs) / 1000,
             (routeEndNs - stampEndNs) / 1000, (endNs - routeEndNs) / 1000, generation, performanceMode)
     }
@@ -561,7 +589,6 @@ class CallAudioEngine {
             return
         }
         val epoch = snapshot[0]
-        val head = CallPlaybackHead()
         val playbackClock = CallPlaybackClock()
         var clockMode = ""
         var outputUs = -1L
@@ -569,7 +596,8 @@ class CallAudioEngine {
         val diagnostic = LongArray(8)
         val row = LongArray(CallAudioTrace.WIDTH)
         while (active) {
-            val track = audioTrack ?: return
+            if (outputRecovery.deviceId != confirmedDeviceId) replacePlaybackOutput(epoch, "route")
+            if (!active) return
             val pullAtNs = System.nanoTime()
             val pullGapExcessUs = ((pullAtNs - previousPullNs - frameNs) / 1000).coerceAtLeast(0)
             previousPullNs = pullAtNs
@@ -593,12 +621,25 @@ class CallAudioEngine {
             var headCallNs = 0L
             var progressCallNs = 0L
             while (active && offset < FRAME_SAMPLES) {
+                if (outputRecovery.deviceId != confirmedDeviceId) replacePlaybackOutput(epoch, "route")
+                val track = audioTrack ?: return
                 var operationNs = System.nanoTime()
-                val written = track.write(silence, offset, FRAME_SAMPLES - offset, AudioTrack.WRITE_NON_BLOCKING)
+                val written = track.write(silence, offset, FRAME_SAMPLES - offset)
                 writeCallNs += System.nanoTime() - operationNs
                 if (written < 0) {
-                    reportFailure(callId, "AudioTrack.write=$written offset=$offset state=${track.playState}")
-                    return
+                    if (written == -899 || written == AudioTrack.ERROR_DEAD_OBJECT) {
+                        LogManager.addLog("WARN", "CallAudio", "output lost backend=${track.name} result=$written offset=$offset")
+                        Thread.sleep(100) // Даём AudioManager доставить подтверждение нового маршрута.
+                        if (!active) return
+                        val changed = outputRecovery.route(confirmedDeviceId)
+                        if (!changed && !outputRecovery.failed()) {
+                            reportFailure(callId, "repeated output failure device=$confirmedDeviceId result=$written"); return
+                        }
+                        replacePlaybackOutput(epoch, "disconnected")
+                        blockedAt = 0L
+                        continue // Незаписанная часть текущего блока остаётся у worker.
+                    }
+                    reportFailure(callId, "${track.name}.write=$written offset=$offset state=${track.playState}"); return
                 }
                 if (written == 0) {
                     zeroWrites++
@@ -619,7 +660,7 @@ class CallAudioEngine {
                 operationNs = System.nanoTime()
                 val position = track.playbackHeadPosition
                 headCallNs += System.nanoTime() - operationNs
-                val played = head.update(position, playFramesWritten)
+                val played = outputPosition.played(position, playFramesWritten)
                 if (played != null) {
                     observedPlayed = played
                     playFramesPlayed = played
@@ -678,7 +719,7 @@ class CallAudioEngine {
     }
 
     /** Reporter управляет устройством независимо от уровня debug; playback не берёт trackLock. */
-    private fun adjustPlaybackBuffer(track: AudioTrack) {
+    private fun adjustPlaybackBuffer(track: CallAudioOutput) {
         synchronized(trackLock) {
             if (!active || audioTrack !== track) return
             val policy = playbackBuffer ?: return
@@ -698,10 +739,10 @@ class CallAudioEngine {
     }
 
     /** Под trackLock, вне playback-loop; уменьшение дренирует очередь без flush и потери PCM. */
-    private fun configurePlaybackBuffer(track: AudioTrack, reason: String, change: CallPlaybackBuffer.Change? = null) {
+    private fun configurePlaybackBuffer(track: CallAudioOutput, reason: String, change: CallPlaybackBuffer.Change? = null) {
         try {
             val previous = track.bufferSizeInFrames
-            val requested = change?.frames ?: FRAME_SAMPLES * 2
+            val requested = change?.frames ?: if (track.fast) FRAME_SAMPLES else FRAME_SAMPLES * 2
             val actual = track.setBufferSizeInFrames(requested)
             check(actual > 0) { "setBufferSizeInFrames($requested)=$actual" }
             val start = if (Build.VERSION.SDK_INT >= 31) track.setStartThresholdInFrames(actual) else actual
@@ -717,10 +758,10 @@ class CallAudioEngine {
             val level = if (actual == requested && (change == null || change.underruns == 0) &&
                 performance == AudioTrack.PERFORMANCE_MODE_LOW_LATENCY) "INFO" else "WARN"
             LogManager.addLog(level, "CallAudio",
-                "playback buffering id=$callId reason=$reason requestedFrames=$requested actualFrames=$actual " +
+                "playback buffering id=$callId backend=${track.name} reason=$reason requestedFrames=$requested actualFrames=$actual " +
                     "previousFrames=$previous startFrames=$start capacityFrames=$capacity underruns=${change?.underruns ?: 0} " +
                     "performanceRequested=${AudioTrack.PERFORMANCE_MODE_LOW_LATENCY} performanceActual=$performance pacing=device")
-            if (playReady && (previous != actual || reason == "route")) {
+            if (playReady && (previous != actual || change == null)) {
                 // Очередь сначала принимает новый размер; устаревшая задача не затронет следующий звонок.
                 mainHandler.post {
                     if (active && audioTrack === track) {
@@ -747,20 +788,20 @@ class CallAudioEngine {
     private fun measureAecDelay() {
         synchronized(recordLock) {
             if (!active || !captureReady || !playReady) return
-            val track = audioTrack ?: return
             val rec = audioRecord ?: return
             try {
-                val tTs = AudioTimestamp()
+                val output = outputLatency(callId)
                 val rTs = AudioTimestamp()
-                val trackOk = track.getTimestamp(tTs)
                 val recOk = rec.getTimestamp(rTs, AudioTimestamp.TIMEBASE_MONOTONIC) == AudioRecord.SUCCESS
-                if (!trackOk || !recOk) {
+                val inputFrames = if (recOk) callCapturePendingFrames(capFramesRead, rTs.framePosition, rTs.nanoTime, System.nanoTime()) else null
+                if (output.outputMs < 0 || inputFrames == null) {
                     LogManager.addLog("WARN", "CallAudio", "getTimestamp unavailable; AEC delay = $AEC_DEFAULT_DELAY_FRAMES frames")
                     NativeLib.callAudioSetAecDelay(AEC_DEFAULT_DELAY_FRAMES)
                     return
                 }
-                val trackLatency = (playFramesWritten - tTs.framePosition).coerceAtLeast(0L)
-                val recLatency = (rTs.framePosition - capFramesRead).coerceAtLeast(0L)
+                // output уже включает HAL и локальную очередь; локальный frame counter нового выхода здесь не используется.
+                val trackLatency = output.outputMs * 48L
+                val recLatency = inputFrames
                 val total = trackLatency + recLatency + AEC_ACOUSTIC_SAMPLES
                 val delayFrames = ((total + FRAME_SAMPLES - 1) / FRAME_SAMPLES).toInt().coerceIn(1, 20)
                 LogManager.addLog("INFO", "CallAudio",

tools/chatgui-android/app/src/main/java/com/utun/chat/data/CallAudioTiming.kt

@@ -1,5 +1,11 @@
 package com.utun.chat.data
 
+/** Остаток захвата на общей монотонной шкале; timestamp может относиться к более раннему периоду HAL. */
+internal fun callCapturePendingFrames(read: Long, frame: Long, stampNs: Long, nowNs: Long): Long? {
+    if (frame < 0 || stampNs <= 0 || nowNs - stampNs !in -20_000_000..500_000_000) return null
+    return (frame - read + (nowNs - stampNs) * 48_000 / 1_000_000_000).coerceAtLeast(0)
+}
+
 /** Шкала AudioRecord после startRecording. Без timestamp продолжаем последний якорь по числу сэмплов. */
 internal class CallCaptureClock {
     private var originUs = Long.MIN_VALUE

tools/chatgui-android/app/src/test/java/com/utun/chat/data/CallAudioTimingTest.kt

@@ -4,6 +4,13 @@ import org.junit.Assert.*
 import org.junit.Test
 
 class CallAudioTimingTest {
+    @Test fun capturePendingIncludesAgeOfHardwareTimestamp() {
+        assertEquals(960L, callCapturePendingFrames(4800, 4320, 970_000_000, 1_000_000_000))
+        assertEquals(0L, callCapturePendingFrames(4800, 4800, 1_000_000_000, 1_000_000_000))
+        assertNull(callCapturePendingFrames(4800, 4320, 100_000_000, 1_000_000_000))
+        assertNull(callCapturePendingFrames(4800, -1, 970_000_000, 1_000_000_000))
+    }
+
     @Test fun playbackUsesPresentationTimeAndMonotonicWrittenAnchor() {
         val c = CallPlaybackClock()
         val fallback = c.update(9600, 8640, 1_000_000, 1, 1, -1, -1)!!