Merge pull request #1350 from vector-im/feature/bma/duplicateNotif

Investigation of duplicate notification.

Author: bmarty

features/invitelist/impl/src/main/kotlin/io/element/android/features/invitelist/impl/InviteListPresenter.kt

@@ -141,7 +141,7 @@ class InviteListPresenter @Inject constructor(
         suspend {
             client.getRoom(roomId)?.use {
                 it.join().getOrThrow()
-                notificationDrawerManager.clearMembershipNotificationForRoom(client.sessionId, roomId)
+                notificationDrawerManager.clearMembershipNotificationForRoom(client.sessionId, roomId, doRender = true)
                 analyticsService.capture(it.toAnalyticsJoinedRoom(JoinedRoom.Trigger.Invite))
             }
             roomId
@@ -152,7 +152,7 @@ class InviteListPresenter @Inject constructor(
         suspend {
             client.getRoom(roomId)?.use {
                 it.leave().getOrThrow()
-                notificationDrawerManager.clearMembershipNotificationForRoom(client.sessionId, roomId)
+                notificationDrawerManager.clearMembershipNotificationForRoom(client.sessionId, roomId, doRender = true)
             }.let { }
         }.runCatchingUpdatingState(declinedAction)
     }

libraries/androidutils/src/main/kotlin/io/element/android/libraries/androidutils/file/File.kt

@@ -25,6 +25,7 @@ import java.util.Locale
 import java.util.UUID
 
 fun File.safeDelete() {
+    if (exists().not()) return
     tryOrNull(
         onError = {
             Timber.e(it, "Error, unable to delete file $path")

libraries/core/src/main/kotlin/io/element/android/libraries/core/log/logger/LoggerTag.kt

@@ -24,10 +24,8 @@ package io.element.android.libraries.core.log.logger
  */
 open class LoggerTag(name: String, parentTag: LoggerTag? = null) {
 
-    object SYNC : LoggerTag("SYNC")
-    object VOIP : LoggerTag("VOIP")
-    object CRYPTO : LoggerTag("CRYPTO")
-    object RENDEZVOUS : LoggerTag("RZ")
+    object PushLoggerTag : LoggerTag("Push")
+    object NotificationLoggerTag : LoggerTag("Notification", PushLoggerTag)
 
     val value: String = if (parentTag == null) {
         name

libraries/matrix/impl/src/main/kotlin/io/element/android/libraries/matrix/impl/tracing/RustTracingTree.kt

@@ -49,7 +49,7 @@ internal class RustTracingTree(private val retrieveFromStackTrace: Boolean) : Ti
             line = location.line,
             level = logLevel,
             target = Target.ELEMENT.filter,
-            message = message,
+            message = if (tag != null) "[$tag] $message" else message,
         )
     }
 

libraries/push/api/src/main/kotlin/io/element/android/libraries/push/api/notifications/NotificationDrawerManager.kt

@@ -21,5 +21,5 @@ import io.element.android.libraries.matrix.api.core.SessionId
 
 interface NotificationDrawerManager {
     fun clearMembershipNotificationForSession(sessionId: SessionId)
-    fun clearMembershipNotificationForRoom(sessionId: SessionId, roomId: RoomId)
+    fun clearMembershipNotificationForRoom(sessionId: SessionId, roomId: RoomId, doRender: Boolean)
 }

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

@@ -24,7 +24,6 @@ import io.element.android.libraries.matrix.api.core.EventId
 import io.element.android.libraries.matrix.api.core.SessionId
 import io.element.android.libraries.matrix.api.pusher.SetHttpPusherData
 import io.element.android.libraries.push.impl.config.PushConfig
-import io.element.android.libraries.push.impl.log.pushLoggerTag
 import io.element.android.libraries.push.impl.pushgateway.PushGatewayNotifyRequest
 import io.element.android.libraries.pushproviders.api.PusherSubscriber
 import io.element.android.libraries.pushstore.api.UserPushStoreFactory
@@ -35,7 +34,7 @@ import javax.inject.Inject
 
 internal const val DEFAULT_PUSHER_FILE_TAG = "mobile"
 
-private val loggerTag = LoggerTag("PushersManager", pushLoggerTag)
+private val loggerTag = LoggerTag("PushersManager", LoggerTag.PushLoggerTag)
 
 @ContributesBinding(AppScope::class)
 class PushersManager @Inject constructor(

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

@@ -20,6 +20,7 @@ import io.element.android.libraries.androidutils.throttler.FirstThrottler
 import io.element.android.libraries.core.cache.CircularCache
 import io.element.android.libraries.core.coroutine.CoroutineDispatchers
 import io.element.android.libraries.core.data.tryOrNull
+import io.element.android.libraries.core.log.logger.LoggerTag
 import io.element.android.libraries.core.meta.BuildMeta
 import io.element.android.libraries.di.AppScope
 import io.element.android.libraries.di.SingleIn
@@ -41,6 +42,8 @@ import kotlinx.coroutines.withContext
 import timber.log.Timber
 import javax.inject.Inject
 
+private val loggerTag = LoggerTag("DefaultNotificationDrawerManager", LoggerTag.NotificationLoggerTag)
+
 /**
  * The NotificationDrawerManager receives notification events as they arrived (from event stream or fcm) and
  * organise them in order to display them in the notification drawer.
@@ -89,7 +92,11 @@ class DefaultNotificationDrawerManager @Inject constructor(
             is NavigationState.Space -> {}
             is NavigationState.Room -> {
                 // Cleanup notification for current room
-                clearMessagesForRoom(navigationState.parentSpace.parentSession.sessionId, navigationState.roomId)
+                clearMessagesForRoom(
+                    sessionId = navigationState.parentSpace.parentSession.sessionId,
+                    roomId = navigationState.roomId,
+                    doRender = true,
+                )
             }
             is NavigationState.Thread -> {
                 onEnteringThread(
@@ -112,13 +119,13 @@ class DefaultNotificationDrawerManager @Inject constructor(
 
     private fun NotificationEventQueue.onNotifiableEventReceived(notifiableEvent: NotifiableEvent) {
         if (buildMeta.lowPrivacyLoggingEnabled) {
-            Timber.d("onNotifiableEventReceived(): $notifiableEvent")
+            Timber.tag(loggerTag.value).d("onNotifiableEventReceived(): $notifiableEvent")
         } else {
-            Timber.d("onNotifiableEventReceived(): is push: ${notifiableEvent.canBeReplaced}")
+            Timber.tag(loggerTag.value).d("onNotifiableEventReceived(): is push: ${notifiableEvent.canBeReplaced}")
         }
 
         if (filteredEventDetector.shouldBeIgnored(notifiableEvent)) {
-            Timber.d("onNotifiableEventReceived(): ignore the event")
+            Timber.tag(loggerTag.value).d("onNotifiableEventReceived(): ignore the event")
             return
         }
 
@@ -132,16 +139,16 @@ class DefaultNotificationDrawerManager @Inject constructor(
      * Events might be grouped and there might not be one notification per event!
      */
     fun onNotifiableEventReceived(notifiableEvent: NotifiableEvent) {
-        updateEvents {
+        updateEvents(doRender = true) {
             it.onNotifiableEventReceived(notifiableEvent)
         }
     }
 
     /**
      * Clear all known events and refresh the notification drawer.
      */
-    fun clearAllMessagesEvents(sessionId: SessionId) {
-        updateEvents {
+    fun clearAllMessagesEvents(sessionId: SessionId, doRender: Boolean) {
+        updateEvents(doRender = doRender) {
             it.clearMessagesForSession(sessionId)
         }
     }
@@ -150,7 +157,7 @@ class DefaultNotificationDrawerManager @Inject constructor(
      * Clear all notifications related to the session and refresh the notification drawer.
      */
     fun clearAllEvents(sessionId: SessionId) {
-        updateEvents {
+        updateEvents(doRender = true) {
             it.clearAllForSession(sessionId)
         }
     }
@@ -160,32 +167,36 @@ class DefaultNotificationDrawerManager @Inject constructor(
      * Used to ignore events related to that room (no need to display notification) and clean any existing notification on this room.
      * Can also be called when a notification for this room is dismissed by the user.
      */
-    fun clearMessagesForRoom(sessionId: SessionId, roomId: RoomId) {
-        updateEvents {
+    fun clearMessagesForRoom(sessionId: SessionId, roomId: RoomId, doRender: Boolean) {
+        updateEvents(doRender = doRender) {
             it.clearMessagesForRoom(sessionId, roomId)
         }
     }
 
     override fun clearMembershipNotificationForSession(sessionId: SessionId) {
-        updateEvents {
+        updateEvents(doRender = true) {
             it.clearMembershipNotificationForSession(sessionId)
         }
     }
 
     /**
      * Clear invitation notification for the provided room.
      */
-    override fun clearMembershipNotificationForRoom(sessionId: SessionId, roomId: RoomId) {
-        updateEvents {
+    override fun clearMembershipNotificationForRoom(
+        sessionId: SessionId,
+        roomId: RoomId,
+        doRender: Boolean,
+    ) {
+        updateEvents(doRender = doRender) {
             it.clearMembershipNotificationForRoom(sessionId, roomId)
         }
     }
 
     /**
      * Clear the notifications for a single event.
      */
-    fun clearEvent(eventId: EventId) {
-        updateEvents {
+    fun clearEvent(eventId: EventId, doRender: Boolean) {
+        updateEvents(doRender = doRender) {
             it.clearEvent(eventId)
         }
     }
@@ -195,14 +206,14 @@ class DefaultNotificationDrawerManager @Inject constructor(
      * Used to ignore events related to that thread (no need to display notification) and clean any existing notification on this room.
      */
     private fun onEnteringThread(sessionId: SessionId, roomId: RoomId, threadId: ThreadId) {
-        updateEvents {
+        updateEvents(doRender = true) {
             it.clearMessagesForThread(sessionId, roomId, threadId)
         }
     }
 
     // TODO EAx Must be per account
     fun notificationStyleChanged() {
-        updateEvents {
+        updateEvents(doRender = true) {
             val newSettings = true // pushDataStore.useCompleteNotificationFormat()
             if (newSettings != useCompleteNotificationFormat) {
                 // Settings has changed, remove all current notifications
@@ -212,41 +223,46 @@ class DefaultNotificationDrawerManager @Inject constructor(
         }
     }
 
-    private fun updateEvents(action: DefaultNotificationDrawerManager.(NotificationEventQueue) -> Unit) {
-        notificationState.updateQueuedEvents(this) { queuedEvents, _ ->
+    private fun updateEvents(
+        doRender: Boolean,
+        action: (NotificationEventQueue) -> Unit,
+    ) {
+        notificationState.updateQueuedEvents { queuedEvents, _ ->
             action(queuedEvents)
         }
-        coroutineScope.refreshNotificationDrawer()
+        coroutineScope.refreshNotificationDrawer(doRender)
     }
 
-    private fun CoroutineScope.refreshNotificationDrawer() = launch {
+    private fun CoroutineScope.refreshNotificationDrawer(doRender: Boolean) = launch {
         // Implement last throttler
         val canHandle = firstThrottler.canHandle()
-        Timber.v("refreshNotificationDrawer(), delay: ${canHandle.waitMillis()} ms")
+        Timber.tag(loggerTag.value).v("refreshNotificationDrawer($doRender), delay: ${canHandle.waitMillis()} ms")
         withContext(dispatchers.io) {
             delay(canHandle.waitMillis())
             try {
-                refreshNotificationDrawerBg()
+                refreshNotificationDrawerBg(doRender)
             } catch (throwable: Throwable) {
                 // It can happen if for instance session has been destroyed. It's a bit ugly to try catch like this, but it's safer
-                Timber.w(throwable, "refreshNotificationDrawerBg failure")
+                Timber.tag(loggerTag.value).w(throwable, "refreshNotificationDrawerBg failure")
             }
         }
     }
 
-    private suspend fun refreshNotificationDrawerBg() {
-        Timber.v("refreshNotificationDrawerBg()")
-        val eventsToRender = notificationState.updateQueuedEvents(this) { queuedEvents, renderedEvents ->
+    private suspend fun refreshNotificationDrawerBg(doRender: Boolean) {
+        Timber.tag(loggerTag.value).v("refreshNotificationDrawerBg($doRender)")
+        val eventsToRender = notificationState.updateQueuedEvents { queuedEvents, renderedEvents ->
             notifiableEventProcessor.process(queuedEvents.rawEvents(), renderedEvents).also {
                 queuedEvents.clearAndAdd(it.onlyKeptEvents())
             }
         }
 
         if (notificationState.hasAlreadyRendered(eventsToRender)) {
-            Timber.d("Skipping notification update due to event list not changing")
+            Timber.tag(loggerTag.value).d("Skipping notification update due to event list not changing")
         } else {
             notificationState.clearAndAddRenderedEvents(eventsToRender)
-            renderEvents(eventsToRender)
+            if (doRender) {
+                renderEvents(eventsToRender)
+            }
             persistEvents()
         }
     }
@@ -265,7 +281,7 @@ class DefaultNotificationDrawerManager @Inject constructor(
 
         eventsForSessions.forEach { (sessionId, notifiableEvents) ->
             val currentUser = tryOrNull(
-                onError = { Timber.e(it, "Unable to retrieve info for user ${sessionId.value}") },
+                onError = { Timber.tag(loggerTag.value).e(it, "Unable to retrieve info for user ${sessionId.value}") },
                 operation = {
                     val client = matrixClientProvider.getOrRestore(sessionId).getOrThrow()
                     // myUserDisplayName cannot be empty else NotificationCompat.MessagingStyle() will crash

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

@@ -16,6 +16,7 @@
 
 package io.element.android.libraries.push.impl.notifications
 
+import io.element.android.libraries.core.log.logger.LoggerTag
 import io.element.android.libraries.matrix.api.timeline.item.event.EventType
 import io.element.android.libraries.push.impl.notifications.model.FallbackNotifiableEvent
 import io.element.android.libraries.push.impl.notifications.model.InviteNotifiableEvent
@@ -29,6 +30,8 @@ import javax.inject.Inject
 
 private typealias ProcessedEvents = List<ProcessedEvent<NotifiableEvent>>
 
+private val loggerTag = LoggerTag("NotifiableEventProcessor", LoggerTag.NotificationLoggerTag)
+
 class NotifiableEventProcessor @Inject constructor(
     private val outdatedDetector: OutdatedEventDetector,
     private val appNavigationStateService: AppNavigationStateService,
@@ -45,10 +48,10 @@ class NotifiableEventProcessor @Inject constructor(
                 is NotifiableMessageEvent -> when {
                     it.shouldIgnoreEventInRoom(appState) -> {
                         ProcessedEvent.Type.REMOVE
-                            .also { Timber.d("notification message removed due to currently viewing the same room or thread") }
+                            .also { Timber.tag(loggerTag.value).d("notification message removed due to currently viewing the same room or thread") }
                     }
                     outdatedDetector.isMessageOutdated(it) -> ProcessedEvent.Type.REMOVE
-                        .also { Timber.d("notification message removed due to being read") }
+                        .also { Timber.tag(loggerTag.value).d("notification message removed due to being read") }
                     else -> ProcessedEvent.Type.KEEP
                 }
                 is SimpleNotifiableEvent -> when (it.type) {
@@ -58,7 +61,7 @@ class NotifiableEventProcessor @Inject constructor(
                 is FallbackNotifiableEvent -> when {
                     it.shouldIgnoreEventInRoom(appState) -> {
                         ProcessedEvent.Type.REMOVE
-                            .also { Timber.d("notification fallback removed due to currently viewing the same room or thread") }
+                            .also { Timber.tag(loggerTag.value).d("notification fallback removed due to currently viewing the same room or thread") }
                     }
                     else -> ProcessedEvent.Type.KEEP
                 }

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

@@ -36,7 +36,6 @@ import io.element.android.libraries.matrix.api.timeline.item.event.TextMessageTy
 import io.element.android.libraries.matrix.api.timeline.item.event.UnknownMessageType
 import io.element.android.libraries.matrix.api.timeline.item.event.VideoMessageType
 import io.element.android.libraries.push.impl.R
-import io.element.android.libraries.push.impl.log.pushLoggerTag
 import io.element.android.libraries.push.impl.notifications.model.FallbackNotifiableEvent
 import io.element.android.libraries.push.impl.notifications.model.InviteNotifiableEvent
 import io.element.android.libraries.push.impl.notifications.model.NotifiableEvent
@@ -47,7 +46,7 @@ import io.element.android.services.toolbox.api.systemclock.SystemClock
 import timber.log.Timber
 import javax.inject.Inject
 
-private val loggerTag = LoggerTag("NotifiableEventResolver", pushLoggerTag)
+private val loggerTag = LoggerTag("NotifiableEventResolver", LoggerTag.NotificationLoggerTag)
 
 /**
  * The notifiable event resolver is able to create a NotifiableEvent (view model for notifications) from an sdk Event.