Check for notification_open duplicate logging based on message ID. (#6112)

- Changed to use the message ID when checking for duplicate
notification_open logging instead of the Activity's Intent. This should
avoid logging again when an app starts another activity using a copy of
the notification's intent
(#6091).

Author: gsakakihara

firebase-messaging/CHANGELOG.md

@@ -1,6 +1,8 @@
 # Unreleased
 * [changed] Retry Topic Subscribe/Unsubscribe operations with exponential
   backoff if they hit a quota error.
+* [changed] Checked for notification_open duplicate logging based on message ID
+  instead of the Activity's Intent.
 
 # 24.0.0
 * [changed] Switched Firelog to use the new TransportBackend.

firebase-messaging/src/main/java/com/google/firebase/messaging/FcmLifecycleCallbacks.java

@@ -24,24 +24,25 @@
 import android.os.Bundle;
 import android.os.Handler;
 import android.os.Looper;
+import android.text.TextUtils;
 import android.util.Log;
-import java.util.Collections;
-import java.util.Set;
-import java.util.WeakHashMap;
+import java.util.ArrayDeque;
+import java.util.Queue;
 
 class FcmLifecycleCallbacks implements Application.ActivityLifecycleCallbacks {
 
-  /** Keep a list of intents that we've seen to avoid accidentally logging events twice. */
-  private final Set<Intent> seenIntents =
-      Collections.newSetFromMap(new WeakHashMap<Intent, Boolean>());
+  private static final int RECENTLY_LOGGED_MESSAGE_IDS_MAX_SIZE = 10;
+
+  /** Last N message IDs that have been logged to prevent duplicate logging. */
+  private final Queue<String> recentlyLoggedMessageIds =
+      new ArrayDeque<>(RECENTLY_LOGGED_MESSAGE_IDS_MAX_SIZE);
 
   // TODO(b/258424124): Migrate to go/firebase-android-executors
   @SuppressLint("ThreadPoolCreation")
   @Override
   public void onActivityCreated(Activity createdActivity, Bundle instanceState) {
     Intent startingIntent = createdActivity.getIntent();
-    if (startingIntent == null || !seenIntents.add(startingIntent)) {
-      // already seen (and logged) this, no need to go any further.
+    if (startingIntent == null) {
       return;
     }
 
@@ -57,12 +58,7 @@ public void onActivityCreated(Activity createdActivity, Bundle instanceState) {
   }
 
   @Override
-  public void onActivityPaused(Activity pausedActivity) {
-    if (pausedActivity.isFinishing()) {
-      // iff the activity is finished we can remove the intent from our "seen" list
-      seenIntents.remove(pausedActivity.getIntent());
-    }
-  }
+  public void onActivityPaused(Activity pausedActivity) {}
 
   @Override
   public void onActivityDestroyed(Activity destroyedActivity) {}
@@ -84,6 +80,14 @@ private void logNotificationOpen(Intent startingIntent) {
     try {
       Bundle extras = startingIntent.getExtras();
       if (extras != null) {
+        String messageId = MessagingAnalytics.getMessageId(extras);
+        if (!TextUtils.isEmpty(messageId)) {
+          if (recentlyLoggedMessageIds.contains(messageId)) {
+            // Already logged, don't log again.
+            return;
+          }
+          recentlyLoggedMessageIds.add(messageId);
+        }
         analyticsData = extras.getBundle(Constants.MessageNotificationKeys.ANALYTICS_DATA);
       }
     } catch (RuntimeException e) {

firebase-messaging/src/test/java/com/google/firebase/messaging/FirebaseMessagingServiceRoboTest.java

@@ -58,11 +58,11 @@
 import com.google.android.gms.cloudmessaging.CloudMessage;
 import com.google.android.gms.cloudmessaging.Rpc;
 import com.google.common.collect.ImmutableSet;
-import com.google.common.collect.Sets;
 import com.google.firebase.FirebaseApp;
 import com.google.firebase.FirebaseOptions;
 import com.google.firebase.iid.FirebaseInstanceIdReceiver;
 import com.google.firebase.messaging.AnalyticsTestHelper.Analytics;
+import com.google.firebase.messaging.Constants.MessagePayloadKeys;
 import com.google.firebase.messaging.testing.AnalyticsValidator;
 import com.google.firebase.messaging.testing.Bundles;
 import com.google.firebase.messaging.testing.FakeConnectorComponent;
@@ -105,6 +105,8 @@ public class FirebaseMessagingServiceRoboTest {
   // blank activity
   public static class MyTestActivity extends Activity {}
 
+  public static class MySecondTestActivity extends Activity {}
+
   private static final AnalyticsValidator analyticsValidator =
       FakeConnectorComponent.getAnalyticsValidator();
 
@@ -501,6 +503,43 @@ public void testNotification_clickAnalytics_recreateActivity() throws Exception
     }
   }
 
+  /** Test that a notification does not re-log events when the same notification is found. */
+  @Test
+  public void notification_clickAnalytics_duplicateMessageId() throws Exception {
+    FirebaseMessaging.getInstance(firebaseApp); // register activity lifecycle friends
+    simulateNotificationMessageWithAnalytics();
+
+    PendingIntent clickPendingIntent = getSingleShownNotification().contentIntent;
+    try (ActivityScenario<MyTestActivity> scenario =
+        dispatchActivityIntentToActivity(clickPendingIntent)) {
+      Intent secondActivityIntent = new Intent();
+      secondActivityIntent.putExtras(shadowOf(clickPendingIntent).getSavedIntent());
+      // Start another Activity with the same notification and check it doesn't log open again.
+      try (ActivityScenario<MySecondTestActivity> secondScenario =
+          ActivityScenario.launch(secondActivityIntent)) {
+        List<AnalyticsValidator.LoggedEvent> events = analyticsValidator.getLoggedEvents();
+        assertThat(events).hasSize(2);
+        AnalyticsValidator.LoggedEvent receiveEvent = events.get(0);
+        assertThat(receiveEvent.getOrigin()).isEqualTo(Analytics.ORIGIN_FCM);
+        assertThat(receiveEvent.getName()).isEqualTo(Analytics.EVENT_NOTIFICATION_RECEIVE);
+        assertThat(receiveEvent.getParams())
+            .string(Analytics.PARAM_MESSAGE_ID)
+            .isEqualTo("composer_key");
+        assertThat(receiveEvent.getParams())
+            .string(Analytics.PARAM_MESSAGE_NAME)
+            .isEqualTo("composer_label");
+        assertThat(receiveEvent.getParams())
+            .integer(Analytics.PARAM_MESSAGE_TIME)
+            .isEqualTo(1234567890);
+        assertThat(receiveEvent.getParams()).doesNotContainKey(Analytics.PARAM_TOPIC);
+
+        AnalyticsValidator.LoggedEvent openEvent = events.get(1);
+        assertThat(openEvent.getOrigin()).isEqualTo(Analytics.ORIGIN_FCM);
+        assertThat(openEvent.getName()).isEqualTo(Analytics.EVENT_NOTIFICATION_OPEN);
+      }
+    }
+  }
+
   /** Test that a notification logs the correct event on dismiss. */
   @Test
   public void testNotification_dismissAnalytics() throws Exception {
@@ -612,6 +651,7 @@ private void simulateNotificationMessageWithAnalytics() throws InterruptedExcept
     // Robo manifest doesn't have a default activity, so set click action so that we get a
     // click pending intent.
     builder.addData(DisplayNotificationRoboTest.KEY_CLICK_ACTION, "click_action");
+    builder.addData(MessagePayloadKeys.MSGID, "msg_id");
     AnalyticsTestHelper.addAnalyticsExtras(builder);
     startServiceViaReceiver(builder.buildIntent());
   }
@@ -766,43 +806,4 @@ private static Set<ServiceConnection> getBoundServiceConnections() {
             .getBoundServiceConnections();
     return ImmutableSet.copyOf(connList.toArray(new ServiceConnection[0]));
   }
-
-  /**
-   * Calls handleIntent on {@link #service} in a background thread and connects any outgoing
-   * bindService calls made in the meantime.
-   *
-   * <p>Returns a CountDownLatch that's finished when the call to handleIntent finishes.
-   */
-  private CountDownLatch handleIntent(Intent intent, int time, TimeUnit unit) throws Exception {
-    long timeoutAtMillis = System.currentTimeMillis() + unit.toMillis(time);
-
-    // Connections that were active before we started
-    Set<ServiceConnection> previousConnections = getBoundServiceConnections();
-
-    // Run the thing that will cause a bindService call in the background
-    CountDownLatch finishedLatch = new CountDownLatch(1);
-    executorService.execute(
-        () -> {
-          service.handleIntent(intent);
-          finishedLatch.countDown();
-        });
-
-    // wait for the call to be made (service connection to appear)
-    while (Sets.difference(getBoundServiceConnections(), previousConnections).isEmpty()) {
-      assertWithMessage("timed out waiting for binder connection")
-          .that(System.currentTimeMillis())
-          .isLessThan(timeoutAtMillis);
-
-      TimeUnit.MILLISECONDS.sleep(50);
-    }
-
-    CountDownLatch flushLatch = new CountDownLatch(1);
-    new Handler(Looper.getMainLooper()).post(flushLatch::countDown);
-    shadowOf(Looper.getMainLooper()).idle();
-
-    long millisRemaining = Math.max(0, timeoutAtMillis - System.currentTimeMillis());
-    assertThat(flushLatch.await(millisRemaining, TimeUnit.MILLISECONDS)).isTrue();
-
-    return finishedLatch;
-  }
 }