Bound Android call AudioTrack working buffer and pace PCM by device

doc/chat_call_arch.md

@@ -134,13 +134,19 @@ capture/play потоки независимо создают и запуска
 INFO-логи Android показывают длительности настройки режима, регистрации callback, BT-профиля, выбора маршрута,
 создания/старта устройств, первого чтения микрофона и первой записи в AudioTrack, а также готовность другого направления.
 Общий `call_audio` логирует время ожидания первого PCM; запись в AudioTrack может содержать начальную тишину.
-Порог запуска AudioTrack — два блока PCM (40мс), отдельно от ёмкости буфера на API 31+;
+Эффективный рабочий буфер AudioTrack на всех поддерживаемых API запрашивается размером
-на API 26–30 запрашивается такой эффективный размер буфера, с учётом ограничений устройства.
+два блока PCM (40мс); на API 31+ отдельно задаётся такой же стартовый порог.
-Прежнее заполнение всей ёмкости на Samsung оставляло около 140мс между written и played
+Ёмкость выделенной памяти может быть больше. Ограничение повторяется по callback фактической
-(на desktop 60–80мс). Лог `playback buffering` показывает принятый порог и ёмкость;
+смены выхода на main, под trackLock; callback старого AudioTrack игнорируется и снимается при stop.
+Подачу PCM задаёт свободное место в AudioTrack, без дополнительного таймера 20мс.
+Частичная запись удерживает остаток одного блока до полной передачи; следующий pull ждёт.
+Сетевой запас остаётся в адаптивном JB, его рост и SoundTouch-догон не изменены.
+Лог `playback buffering` показывает причину настройки, запрошенный/принятый размер, порог и ёмкость;
 ежесекундный `audio summary` — queueUs, текущий порог и underruns; новый episode underrun имеет уровень WARN.
 Это очередь AudioTrack, а не полная сквозная задержка и не сетевой jitter reserve.
-Повторный замер: startFrames=1920 принят, но written-played остался 140мс; одного стартового порога недостаточно.
+Ранее на Samsung startFrames=1920 был принят, но без ограничения рабочего буфера
+written-played оставался 120–160мс; одного стартового порога недостаточно.
+Фактически принятый размер после изменения требует проверки на устройстве, включая смену маршрута.
 
 Диагностика Android при `call=debug`: playback сохраняет один числовой снимок на блок (20мс)
 в кольце 512 элементов, без форматирования/вывода. Отдельный reporter раз в 200мс забирает записи;
@@ -159,6 +165,8 @@ frame/time аппаратного timestamp и время начала опро
 В playback отдельно измеряются writeCallUs (только вызовы write), headCallUs (чтение позиции),
 progressCallUs (публикация позиции ядру), jbSnapshotUs (нативный снимок), writeSpanUs (весь цикл записи)
 и blockUs (pull до формирования строки). При частичных записях длительности вызовов суммируются за блок.
+pullGapExcessUs — превышение интервала между началами соседних pull над 20мс;
+включает ожидание устройства, а не только задержку планировщика (прежнее поле wakeLateUs удалено).
 Старое поле writeUs включало чтение позиции и прогресс: его нельзя трактовать как длительность одного AudioTrack.write.
 Stop дожидается reporter, включая непрерываемый Android-запрос, до освобождения AudioTrack.
 

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

@@ -6,6 +6,7 @@ import android.media.AudioDeviceInfo
 import android.media.AudioFormat
 import android.media.AudioManager
 import android.media.AudioRecord
+import android.media.AudioRouting
 import android.media.AudioTimestamp
 import android.media.AudioTrack
 import android.media.MediaRecorder
@@ -71,6 +72,12 @@ class CallAudioEngine {
     @Volatile private var startElapsedMs = 0L
     @Volatile private var captureElapsedMs = 0L
     private val mainHandler = Handler(Looper.getMainLooper())
+    private val trackRouteListener = AudioRouting.OnRoutingChangedListener { output ->
+        synchronized(trackLock) {
+            val track = audioTrack
+            if (active && track != null && output === track) configurePlaybackBuffer(track, "route")
+        }
+    }
     private val aecDelayRunnable = Runnable { measureAecDelay() }
     private val failed = AtomicBoolean(false)
     var onFailure: ((Long, String) -> Unit)? = null
@@ -176,14 +183,8 @@ class CallAudioEngine {
                         return@runWorker
                     }
                     applyTrackOutputDevice(router.currentOutputDevice)
-                    // Ёмкость устройства не должна становиться постоянной задержкой звонка.
+                    configurePlaybackBuffer(track, "start")
-                    // Два блока оставляют запас на пробуждение playback-потока каждые 20 мс.
+                    track.addOnRoutingChangedListener(trackRouteListener, mainHandler)
-                    val startFrames = FRAME_SAMPLES * 2
-                    val actualStart = if (Build.VERSION.SDK_INT >= 31) track.setStartThresholdInFrames(startFrames)
-                        else track.setBufferSizeInFrames(startFrames)
-                    LogManager.addLog(if (actualStart > 0) "INFO" else "WARN", "CallAudio",
-                        "playback buffering id=$id requestedStart=$startFrames actualStart=$actualStart " +
-                            "bufferFrames=${track.bufferSizeInFrames} capacityFrames=${track.bufferCapacityInFrames}")
                     val trackCreateMs = SystemClock.elapsedRealtime() - createdAt
                     val playedAt = SystemClock.elapsedRealtime()
                     track.play()
@@ -275,6 +276,8 @@ class CallAudioEngine {
         }
         synchronized(trackLock) {
             audioTrack?.let { track ->
+                try { track.removeOnRoutingChangedListener(trackRouteListener) }
+                catch (e: Exception) { LogManager.addLog("WARN", "CallAudio", "track listener removal failed id=$id: ${e.message}") }
                 try { if (track.playState == AudioTrack.PLAYSTATE_PLAYING) track.pause() }
                 catch (e: Exception) { LogManager.addLog("WARN", "CallAudio", "track pause failed id=$id: ${e.message}") }
             }
@@ -480,7 +483,7 @@ class CallAudioEngine {
         val buf = ShortArray(FRAME_SAMPLES)
         val silence = ShortArray(FRAME_SAMPLES)
         val frameNs = FRAME_MS * 1_000_000L
-        var nextNs = System.nanoTime()
+        var previousPullNs = System.nanoTime()
         var firstWrite = true
         val snapshot = LongArray(8)
         if (!NativeLib.callAudioClock(callId, System.nanoTime() / 1000, snapshot)) {
@@ -495,6 +498,8 @@ class CallAudioEngine {
         while (active) {
             val track = audioTrack ?: return
             val pullAtNs = System.nanoTime()
+            val pullGapExcessUs = ((pullAtNs - previousPullNs - frameNs) / 1000).coerceAtLeast(0)
+            previousPullNs = pullAtNs
             val n = NativeLib.callAudioPull(callId, buf)
             val pullEndNs = System.nanoTime()
             val pullUs = (pullEndNs - pullAtNs) / 1000
@@ -561,7 +566,7 @@ class CallAudioEngine {
                 device.copyTo(row)
                 row[0] = nowUs
                 row[3] = playFramesWritten; row[4] = observedPlayed
-                row[5] = pullUs; row[6] = writeCallNs / 1000; row[7] = ((pullAtNs - nextNs) / 1000).coerceAtLeast(0)
+                row[5] = pullUs; row[6] = writeCallNs / 1000; row[7] = pullGapExcessUs
                 row[8] = zeroWrites
                 diagnostic.copyInto(row, 16); row[24] = offset.toLong()
                 row[25] = headCallNs / 1000; row[26] = progressCallNs / 1000; row[27] = writeSpanUs
@@ -575,16 +580,22 @@ class CallAudioEngine {
                     "first playback write id=$callId totalMs=${SystemClock.elapsedRealtime() - startElapsedMs} captureReady=$captureReady")
             }
 
-            /* абсолютный deadline: не даём Thread.sleep накопить систематический дрейф
+            // Темп задаёт освобождение AudioTrack. До полной записи блока следующий PCM не извлекаем:
-             * (важно для стабильного выравнивания рендер↔захват в AEC). */
+            // запас остаётся в адаптивном JB, а вне устройства ожидает не более одного блока (20 мс).
-            nextNs += frameNs
+        }
-            val waitNs = nextNs - System.nanoTime()
+    }
-            if (waitNs > 0) {
+
-                try { Thread.sleep(waitNs / 1_000_000L, (waitNs % 1_000_000L).toInt()) }
+    /** Вызывать под trackLock при создании и после фактической смены выхода, вне playback-loop. */
-                catch (_: InterruptedException) { return }
+    private fun configurePlaybackBuffer(track: AudioTrack, reason: String) {
-            } else {
+        try {
-                nextNs = System.nanoTime()   /* отстали — сбрасываем, не копим долг */
+            val requested = FRAME_SAMPLES * 2
-            }
+            val actual = track.setBufferSizeInFrames(requested)
+            val start = if (Build.VERSION.SDK_INT >= 31) track.setStartThresholdInFrames(requested) else actual
+            LogManager.addLog(if (actual > 0 && actual <= requested && start > 0) "INFO" else "WARN", "CallAudio",
+                "playback buffering id=$callId reason=$reason requestedFrames=$requested actualFrames=$actual " +
+                    "startFrames=$start capacityFrames=${track.bufferCapacityInFrames} pacing=device")
+        } catch (e: Exception) {
+            LogManager.addLog("WARN", "CallAudio", "playback buffer configuration failed id=$callId reason=$reason: ${e.message}")
         }
     }
 

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

@@ -5,7 +5,7 @@ internal class CallAudioTrace(private val id: Long, private val emit: (String, S
     companion object {
         const val WIDTH = 35
         const val CAPACITY = 512
-        // monoUs, routeId, routeType, written, played, pullUs, writeCallUs, wakeLateUs, zeroWrites,
+        // monoUs, routeId, routeType, written, played, pullUs, writeCallUs, pullGapExcessUs, zeroWrites,
         // deviceUnderruns, bufferFrames, startFrames, stampFrame, stampNs, stampReadUs, stampOk,
         // encodedMs, processingMs, reserveMs, spreadMs, pcmSamples, tempo100, jbUnderruns, waiting, accepted
         // headCallUs, progressCallUs, writeSpanUs, jbSnapshotUs, blockUs,
@@ -132,7 +132,7 @@ internal class CallAudioTrace(private val id: Long, private val emit: (String, S
             "jbMs=${range { it[16] + it[17] }} reserveMs=${range { it[18] }} spreadMs=${range { it[19] }} " +
             "pullUs=${range { it[5] }} writeCallUs=${range { it[6] }} headCallUs=${range { it[25] }} " +
             "progressCallUs=${range { it[26] }} writeSpanUs=${range { it[27] }} jbSnapshotUs=${range { it[28] }} " +
-            "blockUs=${range { it[29] }} wakeLateUs=${range { it[7] }} " +
+            "blockUs=${range { it[29] }} pullGapExcessUs=${range { it[7] }} " +
             "tempo=${last[21]} deviceUnderruns=${last[9]} deviceUnderDelta=${last[9] - reportedDeviceUnderruns} " +
             "jbUnderruns=${last[22]} jbUnderDelta=${last[22] - reportedJbUnderruns} " +
             "zeroWrites=${summary.sumOf { it[8] }} missingPcm=${summary.sumOf { (960 - it[20]).coerceAtLeast(0) }} " +
@@ -147,7 +147,7 @@ internal class CallAudioTrace(private val id: Long, private val emit: (String, S
     private fun dump(partial: Boolean) {
         emit("DEBUG", "audio detail call=$id triggerUs=$eventAt reasons=$eventBits events=$eventCount partial=$partial " +
             "bits=start:1,route:2,queue:4,stalled:8,underrun:16 " +
-            "columns=monoUs,routeId,routeType,written,played,pullUs,writeCallUs,wakeLateUs,zeroWrites,deviceUnderruns," +
+            "columns=monoUs,routeId,routeType,written,played,pullUs,writeCallUs,pullGapExcessUs,zeroWrites,deviceUnderruns," +
             "bufferFrames,startFrames,stampFrame,stampNs,stampReadUs,stampOk," +
             "encodedMs,processingMs,reserveMs,spreadMs,pcmSamples,tempo100,jbUnderruns,waiting,accepted," +
             "headCallUs,progressCallUs,writeSpanUs,jbSnapshotUs,blockUs," +