Fix ringing calls not stopping when the other user cancels the call (#4613)

* Fix ringing calls not being automatically canceled

This will keep the sync active while the user is screening an incoming call, allowing receiving a call cancellation event, which will terminate the incoming call ringing early.

* Add extra logs to help debugging ringing call issues.

appnav/src/main/kotlin/io/element/android/appnav/di/SyncOrchestrator.kt

@@ -78,15 +78,21 @@ class SyncOrchestrator @AssistedInject constructor(
     internal fun observeStates() = coroutineScope.launch {
         Timber.tag(tag).d("start observing the app and network state")
 
+        val isAppActiveFlow = combine(
+            appForegroundStateService.isInForeground,
+            appForegroundStateService.isInCall,
+            appForegroundStateService.isSyncingNotificationEvent,
+            appForegroundStateService.hasRingingCall,
+        ) { isInForeground, isInCall, isSyncingNotificationEvent, hasRingingCall ->
+            isInForeground || isInCall || isSyncingNotificationEvent || hasRingingCall
+        }
+
         combine(
             // small debounce to avoid spamming startSync when the state is changing quickly in case of error.
             syncService.syncState.debounce(100.milliseconds),
             networkMonitor.connectivity,
-            appForegroundStateService.isInForeground,
+            isAppActiveFlow,
-            appForegroundStateService.isInCall,
+        ) { syncState, networkState, isAppActive ->
-            appForegroundStateService.isSyncingNotificationEvent,
-        ) { syncState, networkState, isInForeground, isInCall, isSyncingNotificationEvent ->
-            val isAppActive = isInForeground || isInCall || isSyncingNotificationEvent
             val isNetworkAvailable = networkState == NetworkStatus.Connected
 
             Timber.tag(tag).d("isAppActive=$isAppActive, isNetworkAvailable=$isNetworkAvailable")

appnav/src/test/kotlin/io/element/android/appnav/SyncOrchestratorTest.kt

@@ -236,6 +236,50 @@ class SyncOrchestratorTest {
         stopSyncRecorder.assertions().isCalledOnce()
     }
 
+    @Test
+    fun `when the app was in background and we have an incoming ringing call, a sync will be started`() = runTest {
+        val startSyncRecorder = lambdaRecorder<Result<Unit>> { Result.success(Unit) }
+        val stopSyncRecorder = lambdaRecorder<Result<Unit>> { Result.success(Unit) }
+        val syncService = FakeSyncService(initialSyncState = SyncState.Idle).apply {
+            startSyncLambda = startSyncRecorder
+            stopSyncLambda = stopSyncRecorder
+        }
+        val networkMonitor = FakeNetworkMonitor(initialStatus = NetworkStatus.Connected)
+        val appForegroundStateService = FakeAppForegroundStateService(
+            initialForegroundValue = false,
+            initialIsSyncingNotificationEventValue = false,
+            initialHasRingingCall = false,
+        )
+        val syncOrchestrator = createSyncOrchestrator(
+            syncService = syncService,
+            networkMonitor = networkMonitor,
+            appForegroundStateService = appForegroundStateService,
+        )
+
+        // We start observing
+        syncOrchestrator.observeStates()
+
+        // Advance the time to make sure the orchestrator has had time to start processing the inputs
+        advanceTimeBy(100.milliseconds)
+
+        // Start sync was never called
+        startSyncRecorder.assertions().isNeverCalled()
+
+        // Now we receive a ringing call
+        appForegroundStateService.updateHasRingingCall(true)
+
+        // Start sync will be called shortly after
+        advanceTimeBy(1.milliseconds)
+        startSyncRecorder.assertions().isCalledOnce()
+
+        // If the sync is running and the ringing call notification is now over, the sync stops after a delay
+        syncService.emitSyncState(SyncState.Running)
+        appForegroundStateService.updateHasRingingCall(false)
+
+        advanceTimeBy(10.seconds)
+        stopSyncRecorder.assertions().isCalledOnce()
+    }
+
     @Test
     fun `when the app is in foreground, we sync for a notification and a call is ongoing, the sync will only stop when all conditions are false`() = runTest {
         val startSyncRecorder = lambdaRecorder<Result<Unit>> { Result.success(Unit) }

features/call/impl/src/main/kotlin/io/element/android/features/call/impl/utils/ActiveCallManager.kt

@@ -26,6 +26,7 @@ import io.element.android.libraries.matrix.api.MatrixClientProvider
 import io.element.android.libraries.push.api.notifications.ForegroundServiceType
 import io.element.android.libraries.push.api.notifications.NotificationIdProvider
 import io.element.android.libraries.push.api.notifications.OnMissedCallNotificationHandler
+import io.element.android.services.appnavstate.api.AppForegroundStateService
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.ExperimentalCoroutinesApi
 import kotlinx.coroutines.Job
@@ -87,7 +88,9 @@ class DefaultActiveCallManager @Inject constructor(
     private val notificationManagerCompat: NotificationManagerCompat,
     private val matrixClientProvider: MatrixClientProvider,
     private val defaultCurrentCallService: DefaultCurrentCallService,
+    private val appForegroundStateService: AppForegroundStateService,
 ) : ActiveCallManager {
+    private val tag = "DefaultActiveCallManager"
     private var timedOutCallJob: Job? = null
 
     @VisibleForTesting(otherwise = VisibleForTesting.PRIVATE)
@@ -106,9 +109,11 @@ class DefaultActiveCallManager @Inject constructor(
 
     override suspend fun registerIncomingCall(notificationData: CallNotificationData) {
         mutex.withLock {
+            appForegroundStateService.updateHasRingingCall(true)
+            Timber.tag(tag).d("Received incoming call for room id: ${notificationData.roomId}")
             if (activeCall.value != null) {
                 displayMissedCallNotification(notificationData)
-                Timber.w("Already have an active call, ignoring incoming call: $notificationData")
+                Timber.tag(tag).w("Already have an active call, ignoring incoming call: $notificationData")
                 return
             }
             activeCall.value = ActiveCall(
@@ -129,6 +134,7 @@ class DefaultActiveCallManager @Inject constructor(
 
             // Acquire a wake lock to keep the device awake during the incoming call, so we can process the room info data
             if (activeWakeLock?.isHeld == false) {
+                Timber.tag(tag).d("Acquiring partial wakelock")
                 activeWakeLock.acquire(ElementCallConfig.RINGING_CALL_DURATION_SECONDS * 1000L)
             }
         }
@@ -139,10 +145,13 @@ class DefaultActiveCallManager @Inject constructor(
      */
     @VisibleForTesting(otherwise = VisibleForTesting.PRIVATE)
     suspend fun incomingCallTimedOut(displayMissedCallNotification: Boolean) = mutex.withLock {
+        Timber.tag(tag).d("Incoming call timed out")
+
         val previousActiveCall = activeCall.value ?: return
         val notificationData = (previousActiveCall.callState as? CallState.Ringing)?.notificationData ?: return
         activeCall.value = null
         if (activeWakeLock?.isHeld == true) {
+            Timber.tag(tag).d("Releasing partial wakelock after timeout")
             activeWakeLock.release()
         }
 
@@ -155,11 +164,12 @@ class DefaultActiveCallManager @Inject constructor(
 
     override suspend fun hungUpCall(callType: CallType) = mutex.withLock {
         if (activeCall.value?.callType != callType) {
-            Timber.w("Call type $callType does not match the active call type, ignoring")
+            Timber.tag(tag).w("Call type $callType does not match the active call type, ignoring")
             return
         }
         cancelIncomingCallNotification()
         if (activeWakeLock?.isHeld == true) {
+            Timber.tag(tag).d("Releasing partial wakelock after hang up")
             activeWakeLock.release()
         }
         timedOutCallJob?.cancel()
@@ -169,6 +179,7 @@ class DefaultActiveCallManager @Inject constructor(
     override suspend fun joinedCall(callType: CallType) = mutex.withLock {
         cancelIncomingCallNotification()
         if (activeWakeLock?.isHeld == true) {
+            Timber.tag(tag).d("Releasing partial wakelock after joining call")
             activeWakeLock.release()
         }
         timedOutCallJob?.cancel()
@@ -181,6 +192,7 @@ class DefaultActiveCallManager @Inject constructor(
 
     @SuppressLint("MissingPermission")
     private suspend fun showIncomingCallNotification(notificationData: CallNotificationData) {
+        Timber.tag(tag).d("Displaying ringing call notification")
         val notification = ringingCallNotificationCreator.createNotification(
             sessionId = notificationData.sessionId,
             roomId = notificationData.roomId,
@@ -204,10 +216,13 @@ class DefaultActiveCallManager @Inject constructor(
     }
 
     private fun cancelIncomingCallNotification() {
+        appForegroundStateService.updateHasRingingCall(false)
+        Timber.tag(tag).d("Ringing call notification cancelled")
         notificationManagerCompat.cancel(NotificationIdProvider.getForegroundServiceNotificationId(ForegroundServiceType.INCOMING_CALL))
     }
 
     private fun displayMissedCallNotification(notificationData: CallNotificationData) {
+        Timber.tag(tag).d("Displaying missed call notification")
         coroutineScope.launch {
             onMissedCallNotificationHandler.addMissedCallNotification(
                 sessionId = notificationData.sessionId,
@@ -227,14 +242,14 @@ class DefaultActiveCallManager @Inject constructor(
             .flatMapLatest { activeCall ->
                 val callType = activeCall.callType as CallType.RoomCall
                 // Get a flow of updated `hasRoomCall` and `activeRoomCallParticipants` values for the room
-                matrixClientProvider.getOrRestore(callType.sessionId).getOrNull()
+                val room = matrixClientProvider.getOrRestore(callType.sessionId).getOrNull()?.getRoom(callType.roomId) ?: run {
-                    ?.getRoom(callType.roomId)
+                    Timber.tag(tag).d("Couldn't find room for incoming call: $activeCall")
-                    ?.roomInfoFlow
+                    return@flatMapLatest flowOf()
-                    ?.map {
+                }
-                        Timber.d("Has room call status changed for ringing call: ${it.hasRoomCall}")
+                room.roomInfoFlow.map {
-                        it.hasRoomCall to (callType.sessionId in it.activeRoomCallParticipants)
+                    Timber.tag(tag).d("Has room call status changed for ringing call: ${it.hasRoomCall}")
-                    }
+                    it.hasRoomCall to (callType.sessionId in it.activeRoomCallParticipants)
-                    ?: flowOf()
+                }
             }
             // We only want to check if the room active call status changes
             .distinctUntilChanged()

features/call/impl/src/test/kotlin/io/element/android/features/call/utils/DefaultActiveCallManagerTest.kt

@@ -35,6 +35,7 @@ import io.element.android.libraries.push.api.notifications.NotificationIdProvide
 import io.element.android.libraries.push.test.notifications.FakeImageLoaderHolder
 import io.element.android.libraries.push.test.notifications.FakeOnMissedCallNotificationHandler
 import io.element.android.libraries.push.test.notifications.push.FakeNotificationBitmapLoader
+import io.element.android.services.appnavstate.test.FakeAppForegroundStateService
 import io.element.android.tests.testutils.lambda.lambdaRecorder
 import io.element.android.tests.testutils.lambda.value
 import io.mockk.mockk
@@ -323,5 +324,6 @@ class DefaultActiveCallManagerTest {
         notificationManagerCompat = notificationManagerCompat,
         matrixClientProvider = matrixClientProvider,
         defaultCurrentCallService = DefaultCurrentCallService(),
+        appForegroundStateService = FakeAppForegroundStateService(),
     )
 }

libraries/push/impl/src/main/kotlin/io/element/android/libraries/push/impl/notifications/CallNotificationEventResolver.kt

@@ -17,6 +17,7 @@ import io.element.android.libraries.push.impl.R
 import io.element.android.libraries.push.impl.notifications.model.NotifiableEvent
 import io.element.android.libraries.push.impl.notifications.model.NotifiableRingingCallEvent
 import io.element.android.services.toolbox.api.strings.StringProvider
+import timber.log.Timber
 import javax.inject.Inject
 
 /**
@@ -69,6 +70,9 @@ class DefaultCallNotificationEventResolver @Inject constructor(
                     senderAvatarUrl = senderAvatarUrl,
                 )
             } else {
+                val now = System.currentTimeMillis()
+                val elapsed = now - timestamp
+                Timber.d("Event $eventId is call notify but should not ring: $timestamp vs $now ($elapsed ms elapsed), notify: ${content.type}")
                 // Create a simple message notification event
                 buildNotifiableMessageEvent(
                     sessionId = sessionId,

libraries/push/impl/src/main/kotlin/io/element/android/libraries/push/impl/notifications/DefaultNotifiableEventResolver.kt

@@ -92,8 +92,9 @@ class DefaultNotifiableEventResolver @Inject constructor(
         return notificationData.flatMap {
             if (it == null) {
                 Timber.tag(loggerTag.value).d("No notification data found for event $eventId")
-                return@flatMap Result.failure(ResolvingException("Unable to resolve event"))
+                return@flatMap Result.failure(ResolvingException("Unable to resolve event $eventId"))
             } else {
+                Timber.tag(loggerTag.value).d("Found notification item for $eventId")
                 it.asNotifiableEvent(client, sessionId)
             }
         }

libraries/push/impl/src/main/kotlin/io/element/android/libraries/push/impl/push/DefaultPushHandler.kt

@@ -133,10 +133,12 @@ class DefaultPushHandler @Inject constructor(
                         is ResolvedPushEvent.Event -> {
                             when (val notifiableEvent = resolvedPushEvent.notifiableEvent) {
                                 is NotifiableRingingCallEvent -> {
+                                    Timber.tag(loggerTag.value).d("Notifiable event ${pushData.eventId} is ringing call: $notifiableEvent")
                                     onNotifiableEventReceived.onNotifiableEventReceived(notifiableEvent)
                                     handleRingingCallEvent(notifiableEvent)
                                 }
                                 else -> {
+                                    Timber.tag(loggerTag.value).d("Notifiable event ${pushData.eventId} is normal event: $notifiableEvent")
                                     val userPushStore = userPushStoreFactory.getOrCreate(userId)
                                     val areNotificationsEnabled = userPushStore.getNotificationEnabledForDevice().first()
                                     if (areNotificationsEnabled) {

services/appnavstate/api/src/main/kotlin/io/element/android/services/appnavstate/api/AppForegroundStateService.kt

@@ -18,6 +18,11 @@ interface AppForegroundStateService {
      */
     val isInForeground: StateFlow<Boolean>
 
+    /**
+     * Updates to whether the app is active because an incoming ringing call is happening will be emitted here.
+     */
+    val hasRingingCall: StateFlow<Boolean>
+
     /**
      * Updates to whether the app is in an active call or not will be emitted here.
      */
@@ -38,6 +43,11 @@ interface AppForegroundStateService {
      */
     fun updateIsInCallState(isInCall: Boolean)
 
+    /**
+     * Update the 'has ringing call' state.
+     */
+    fun updateHasRingingCall(hasRingingCall: Boolean)
+
     /**
      * Update the active state for the syncing notification event flow.
      */

services/appnavstate/impl/src/main/kotlin/io/element/android/services/appnavstate/impl/DefaultAppForegroundStateService.kt

@@ -17,6 +17,7 @@ class DefaultAppForegroundStateService : AppForegroundStateService {
     override val isInForeground = MutableStateFlow(false)
     override val isInCall = MutableStateFlow(false)
     override val isSyncingNotificationEvent = MutableStateFlow(false)
+    override val hasRingingCall = MutableStateFlow(false)
 
     private val appLifecycle: Lifecycle by lazy { ProcessLifecycleOwner.get().lifecycle }
 
@@ -28,6 +29,10 @@ class DefaultAppForegroundStateService : AppForegroundStateService {
         this.isInCall.value = isInCall
     }
 
+    override fun updateHasRingingCall(hasRingingCall: Boolean) {
+        this.hasRingingCall.value = hasRingingCall
+    }
+
     override fun updateIsSyncingNotificationEvent(isSyncingNotificationEvent: Boolean) {
         this.isSyncingNotificationEvent.value = isSyncingNotificationEvent
     }

services/appnavstate/test/src/main/kotlin/io/element/android/services/appnavstate/test/FakeAppForegroundStateService.kt

@@ -13,11 +13,13 @@ import kotlinx.coroutines.flow.MutableStateFlow
 class FakeAppForegroundStateService(
     initialForegroundValue: Boolean = true,
     initialIsInCallValue: Boolean = false,
-    initialIsSyncingNotificationEventValue: Boolean = false
+    initialIsSyncingNotificationEventValue: Boolean = false,
+    initialHasRingingCall: Boolean = false,
 ) : AppForegroundStateService {
     override val isInForeground = MutableStateFlow(initialForegroundValue)
     override val isInCall = MutableStateFlow(initialIsInCallValue)
     override val isSyncingNotificationEvent = MutableStateFlow(initialIsSyncingNotificationEventValue)
+    override val hasRingingCall = MutableStateFlow(initialHasRingingCall)
 
     override fun startObservingForeground() {
         // No-op
@@ -34,4 +36,8 @@ class FakeAppForegroundStateService(
     override fun updateIsSyncingNotificationEvent(isSyncingNotificationEvent: Boolean) {
         this.isSyncingNotificationEvent.value = isSyncingNotificationEvent
     }
+
+    override fun updateHasRingingCall(hasRingingCall: Boolean) {
+        this.hasRingingCall.value = hasRingingCall
+    }
 }