Merge pull request #681 from d4rken-org/worktree-ca-duck-noop-diag

Reaction: Retry conversation volume lowering when the system ignores it

app/src/main/java/eu/darken/capod/common/MediaControl.kt

@@ -267,10 +267,11 @@ class MediaControl @Inject constructor(
      * the prior + the volume actually applied, so the caller can later restore it and detect whether
      * the user changed the volume in the meantime.
      *
-     * Returns `null` (no-op) when nothing is playing, the device has fixed volume, or the computed
-     * target wouldn't actually lower the volume. No [AudioManager.FLAG_SHOW_UI] — this fires on a
-     * frequent push event and the volume panel flashing would be noisy. The applied target is read
-     * back from the system because Bluetooth absolute-volume routes can quantize the requested value.
+     * Returns `null` (no-op) when nothing is playing, the device has fixed volume, the computed
+     * target wouldn't actually lower the volume, or the write didn't land. No
+     * [AudioManager.FLAG_SHOW_UI] — this fires on a frequent push event and the volume panel
+     * flashing would be noisy. The applied target is read back from the system because Bluetooth
+     * absolute-volume routes can quantize the requested value.
      */
     fun duckMusicVolume(reductionPercent: Int): VolumeDuck? {
         if (!audioManager.isMusicActive) {
@@ -297,8 +298,21 @@ class MediaControl @Inject constructor(
         return try {
             audioManager.setStreamVolume(AudioManager.STREAM_MUSIC, target, 0)
             val applied = audioManager.getStreamVolume(AudioManager.STREAM_MUSIC)
-            log(TAG, INFO) { "duckMusicVolume($percent%): $prior -> $applied (requested $target)" }
-            VolumeDuck(priorVolume = prior, appliedVolume = applied)
+            if (applied >= prior) {
+                // No attenuation happened. Either the write was accepted and dropped (ColorOS 16
+                // does this while the app is in the background: no exception, volume untouched),
+                // the route quantized the target back up to where it started, or the user raised
+                // the volume in between. Reporting a duck would have the caller track a session
+                // that never attenuated anything, and later "restore" a level it never left.
+                log(TAG, WARN) {
+                    "duckMusicVolume($percent%): volume did not decrease, $prior -> $applied " +
+                            "(requested $target, min=$min, max=$max)"
+                }
+                null
+            } else {
+                log(TAG, INFO) { "duckMusicVolume($percent%): $prior -> $applied (requested $target)" }
+                VolumeDuck(priorVolume = prior, appliedVolume = applied)
+            }
         } catch (e: SecurityException) {
             // setStreamVolume throws under Do-Not-Disturb without notification policy access.
             log(TAG, WARN) { "duckMusicVolume: setStreamVolume denied: ${e.message}" }

app/src/main/java/eu/darken/capod/common/bluetooth/BleScanner.kt

@@ -79,11 +79,22 @@ class BleScanner @Inject constructor(
         }
 
         val callback = object : ScanCallback() {
-            var lastScanAt = timeSource.currentTimeMillis()
+            // Updated outside the log lambdas below: those only run while a logger is attached, so
+            // folding the bookkeeping into them made the first delay of a debug recording measure
+            // the time since the *previous* recording ended instead of the actual callback gap.
+            // Monotonic clock, so a wall-clock correction can't fabricate a gap either.
+            var lastScanAt = timeSource.elapsedRealtime()
+
+            private fun takeDelay(): Long {
+                val now = timeSource.elapsedRealtime()
+                val delay = now - lastScanAt
+                lastScanAt = now
+                return delay
+            }
+
             override fun onScanResult(callbackType: Int, result: ScanResult) {
+                val delay = takeDelay()
                 log(TAG, VERBOSE) {
-                    val delay = timeSource.currentTimeMillis() - lastScanAt
-                    lastScanAt = timeSource.currentTimeMillis()
                     "onScanResult(delay=${delay}ms, callbackType=$callbackType, ${result.logSummary()})"
                 }
 
@@ -91,11 +102,8 @@ class BleScanner @Inject constructor(
             }
 
             override fun onBatchScanResults(results: MutableList<ScanResult>) {
-                log(TAG, VERBOSE) {
-                    val delay = timeSource.currentTimeMillis() - lastScanAt
-                    lastScanAt = timeSource.currentTimeMillis()
-                    "onBatchScanResults(delay=${delay}ms, ${results.logSummary()})"
-                }
+                val delay = takeDelay()
+                log(TAG, VERBOSE) { "onBatchScanResults(delay=${delay}ms, ${results.logSummary()})" }
 
                 trySend(filterResults(results))
             }

app/src/test/java/eu/darken/capod/common/MediaControlTest.kt

@@ -5,6 +5,8 @@ import android.media.AudioManager
 import android.media.AudioPlaybackConfiguration
 import android.os.Handler
 import android.view.KeyEvent
+import io.kotest.matchers.nulls.shouldBeNull
+import io.kotest.matchers.shouldBe
 import io.mockk.CapturingSlot
 import io.mockk.Runs
 import io.mockk.clearMocks
@@ -515,4 +517,51 @@ class MediaControlTest : BaseTest() {
         assertFalse(undrained.wasRecentlyPausedByCap)
         verify(exactly = 2) { freshAudioManager.dispatchMediaKeyEvent(any()) }
     }
+
+    /**
+     * The read-back deliberately differs from the requested target: Bluetooth absolute-volume routes
+     * quantize, and the caller has to restore against what actually landed, not what was asked for.
+     */
+    @Test
+    fun `duckMusicVolume reports the level the system actually applied`() {
+        every { audioManager.isMusicActive } returns true
+        every { audioManager.isVolumeFixed } returns false
+        every { audioManager.getStreamMaxVolume(AudioManager.STREAM_MUSIC) } returns 100
+        every { audioManager.getStreamVolume(AudioManager.STREAM_MUSIC) } returnsMany listOf(40, 22)
+
+        mediaControl.duckMusicVolume(50) shouldBe MediaControl.VolumeDuck(priorVolume = 40, appliedVolume = 22)
+
+        verify { audioManager.setStreamVolume(AudioManager.STREAM_MUSIC, 20, 0) }
+    }
+
+    /**
+     * A volume that came back *higher* (user raised it between the two reads) is not a duck either.
+     * Reporting one would have the caller later "restore" downwards, undoing the user's change.
+     */
+    @Test
+    fun `duckMusicVolume treats a raised volume as a no-op`() {
+        every { audioManager.isMusicActive } returns true
+        every { audioManager.isVolumeFixed } returns false
+        every { audioManager.getStreamMaxVolume(AudioManager.STREAM_MUSIC) } returns 100
+        every { audioManager.getStreamVolume(AudioManager.STREAM_MUSIC) } returnsMany listOf(40, 55)
+
+        mediaControl.duckMusicVolume(50).shouldBeNull()
+    }
+
+    /**
+     * ColorOS 16 accepts `setStreamVolume` from a backgrounded app, raises nothing, and leaves the
+     * volume where it was. Reporting that as a duck had the caller track a session that never
+     * attenuated anything and later restore a level that was never left.
+     */
+    @Test
+    fun `duckMusicVolume treats a silently ignored write as a no-op`() {
+        every { audioManager.isMusicActive } returns true
+        every { audioManager.isVolumeFixed } returns false
+        every { audioManager.getStreamMaxVolume(AudioManager.STREAM_MUSIC) } returns 100
+        every { audioManager.getStreamVolume(AudioManager.STREAM_MUSIC) } returnsMany listOf(40, 40)
+
+        mediaControl.duckMusicVolume(100).shouldBeNull()
+
+        verify { audioManager.setStreamVolume(AudioManager.STREAM_MUSIC, 0, 0) }
+    }
 }

app/src/test/java/eu/darken/capod/reaction/core/conversation/ConversationReactionTest.kt

@@ -180,6 +180,31 @@ class ConversationReactionTest : BaseTest() {
         job.cancel()
     }
 
+    /**
+     * A duck the system refused (ColorOS 16 accepts `setStreamVolume` from a backgrounded app and
+     * leaves the volume alone) must leave no session behind: nothing to restore on the terminal, and
+     * no armed backstop that would restore a level that was never left. A repeat START retries the
+     * duck rather than treating the dead session as a keep-alive.
+     */
+    @Test
+    fun `LOWER_VOLUME refused duck arms nothing and never restores`() = runTest(UnconfinedTestDispatcher()) {
+        every { mediaControl.duckMusicVolume(any()) } returns null
+        val job = launchReaction()
+
+        emit(primaryAddress, ConversationAwarenessEvent.START)
+        verify(exactly = 1) { mediaControl.duckMusicVolume(50) }
+
+        emit(primaryAddress, ConversationAwarenessEvent.START)
+        verify(exactly = 2) { mediaControl.duckMusicVolume(50) }
+
+        emit(primaryAddress, ConversationAwarenessEvent.STOP)
+        advanceBoth(stopSettleMs + 50)
+        advanceBoth(staleTimeoutMs + 500)
+
+        verify(exactly = 0) { mediaControl.restoreMusicVolume(any()) }
+        job.cancel()
+    }
+
     @Test
     fun `LOWER_VOLUME missed STOP restores via stale timeout`() = runTest(UnconfinedTestDispatcher()) {
         val job = launchReaction()