From d3d49337e55c70d61358e028d879dea4d95f8014 Mon Sep 17 00:00:00 2001 From: Will Brockman Date: Mon, 10 Feb 2020 19:43:03 -0500 Subject: [PATCH] Notification statsd logs: Visibility changes. These are currently logged in NotificationRecord.setVisibility(). Rather than add a dependency on the NotificationRecordLogger to NotificationRecord, I've passed one in to that method. I considered but rejected doing the same for NOTIFICATION_INTERRUPTION, which is logged similarly in NotificationRecord.setInterruptive(). The circumstances under which that log gets written are challenging to understand, and I'm not currently convinced that it is worth porting. Test: atest NotificationManagerServiceTest NotificiationRecordLoggerTest Bug: 146488473 Change-Id: I956cd4ededa470f91244305d4c26fb981d4c94a4 --- .../NotificationManagerService.java | 8 +- .../notification/NotificationRecord.java | 4 +- .../NotificationRecordLogger.java | 34 +++++++- .../NotificationRecordLoggerImpl.java | 23 ++++-- .../NotificationManagerServiceTest.java | 77 +++++++++++++++---- .../NotificationRecordLoggerFake.java | 31 +++++--- 6 files changed, 134 insertions(+), 43 deletions(-) diff --git a/services/core/java/com/android/server/notification/NotificationManagerService.java b/services/core/java/com/android/server/notification/NotificationManagerService.java index 916b63bee0e89..8b82072d45446 100755 --- a/services/core/java/com/android/server/notification/NotificationManagerService.java +++ b/services/core/java/com/android/server/notification/NotificationManagerService.java @@ -1055,7 +1055,7 @@ public class NotificationManagerService extends SystemService { if (DBG) Slog.d(TAG, "Marking notification as visible " + nv.key); reportSeen(r); } - r.setVisibility(true, nv.rank, nv.count); + r.setVisibility(true, nv.rank, nv.count, mNotificationRecordLogger); mAssistants.notifyAssistantVisibilityChangedLocked(r.getSbn(), true); boolean isHun = (nv.location == NotificationVisibility.NotificationLocation.LOCATION_FIRST_HEADS_UP); @@ -1074,7 +1074,7 @@ public class NotificationManagerService extends SystemService { for (NotificationVisibility nv : noLongerVisibleKeys) { NotificationRecord r = mNotificationsByKey.get(nv.key); if (r == null) continue; - r.setVisibility(false, nv.rank, nv.count); + r.setVisibility(false, nv.rank, nv.count, mNotificationRecordLogger); mAssistants.notifyAssistantVisibilityChangedLocked(r.getSbn(), false); nv.recycle(); } @@ -6468,7 +6468,7 @@ public class NotificationManagerService extends SystemService { mUsageStats.registerPostedByApp(r); r.setInterruptive(isVisuallyInterruptive(null, r)); } else { - old = mNotificationList.get(index); + old = mNotificationList.get(index); // Potentially *changes* old mNotificationList.set(index, r); mUsageStats.registerUpdatedByApp(r, old); // Make sure we don't lose the foreground service state. @@ -6537,7 +6537,7 @@ public class NotificationManagerService extends SystemService { maybeRecordInterruptionLocked(r); // Log event to statsd - mNotificationRecordLogger.logNotificationReported(r, old, position, + mNotificationRecordLogger.maybeLogNotificationPosted(r, old, position, buzzBeepBlinkLoggingCode); } finally { int N = mEnqueuedNotifications.size(); diff --git a/services/core/java/com/android/server/notification/NotificationRecord.java b/services/core/java/com/android/server/notification/NotificationRecord.java index 4785da9a59229..0ada58e1ce162 100644 --- a/services/core/java/com/android/server/notification/NotificationRecord.java +++ b/services/core/java/com/android/server/notification/NotificationRecord.java @@ -909,7 +909,8 @@ public final class NotificationRecord { /** * Set the visibility of the notification. */ - public void setVisibility(boolean visible, int rank, int count) { + public void setVisibility(boolean visible, int rank, int count, + NotificationRecordLogger notificationRecordLogger) { final long now = System.currentTimeMillis(); mVisibleSinceMs = visible ? now : mVisibleSinceMs; stats.onVisibilityChanged(visible); @@ -927,6 +928,7 @@ public final class NotificationRecord { getFreshnessMs(now), 0, // exposure time rank); + notificationRecordLogger.logNotificationVisibility(this, visible); } /** diff --git a/services/core/java/com/android/server/notification/NotificationRecordLogger.java b/services/core/java/com/android/server/notification/NotificationRecordLogger.java index 2f7854226c5c9..eaca066f026ff 100644 --- a/services/core/java/com/android/server/notification/NotificationRecordLogger.java +++ b/services/core/java/com/android/server/notification/NotificationRecordLogger.java @@ -41,13 +41,14 @@ import java.util.Objects; public interface NotificationRecordLogger { /** - * Logs a NotificationReported atom reflecting the posting or update of a notification. + * May log a NotificationReported atom reflecting the posting or update of a notification. * @param r The new NotificationRecord. If null, no action is taken. * @param old The previous NotificationRecord. Null if there was no previous record. * @param position The position at which this notification is ranked. * @param buzzBeepBlink Logging code reflecting whether this notification alerted the user. */ - void logNotificationReported(@Nullable NotificationRecord r, @Nullable NotificationRecord old, + void maybeLogNotificationPosted(@Nullable NotificationRecord r, + @Nullable NotificationRecord old, int position, int buzzBeepBlink); /** @@ -61,6 +62,14 @@ public interface NotificationRecordLogger { @NotificationListenerService.NotificationCancelReason int reason, @NotificationStats.DismissalSurface int dismissalSurface); + /** + * Logs a notification visibility change event using UiEventReported (event ids from the + * NotificationEvents enum). + * @param r The NotificationRecord. If null, no action is taken. + * @param visible True if the notification became visible. + */ + void logNotificationVisibility(@Nullable NotificationRecord r, boolean visible); + /** * The UiEvent enums that this class can log. */ @@ -145,6 +154,7 @@ public interface NotificationRecordLogger { @Override public int getId() { return mId; } + public static NotificationCancelledEvent fromCancelReason( @NotificationListenerService.NotificationCancelReason int reason, @NotificationStats.DismissalSurface int surface) { @@ -191,6 +201,24 @@ public interface NotificationRecordLogger { } } + enum NotificationEvent implements UiEventLogger.UiEventEnum { + @UiEvent(doc = "Notification became visible.") + NOTIFICATION_OPEN(197), + @UiEvent(doc = "Notification stopped being visible.") + NOTIFICATION_CLOSE(198); + + private final int mId; + NotificationEvent(int id) { + mId = id; + } + @Override public int getId() { + return mId; + } + + public static NotificationEvent fromVisibility(boolean visible) { + return visible ? NOTIFICATION_OPEN : NOTIFICATION_CLOSE; + } + } /** * A helper for extracting logging information from one or two NotificationRecords. */ @@ -209,7 +237,7 @@ public interface NotificationRecordLogger { /** * @return True if old is null, alerted, or important logged fields have changed. */ - boolean shouldLog(int buzzBeepBlink) { + boolean shouldLogReported(int buzzBeepBlink) { if (r == null) { return false; } diff --git a/services/core/java/com/android/server/notification/NotificationRecordLoggerImpl.java b/services/core/java/com/android/server/notification/NotificationRecordLoggerImpl.java index bb23d1e876dc4..9fcac257d328e 100644 --- a/services/core/java/com/android/server/notification/NotificationRecordLoggerImpl.java +++ b/services/core/java/com/android/server/notification/NotificationRecordLoggerImpl.java @@ -26,13 +26,13 @@ import com.android.internal.util.FrameworkStatsLog; */ public class NotificationRecordLoggerImpl implements NotificationRecordLogger { - UiEventLogger mUiEventLogger = new UiEventLoggerImpl(); + private UiEventLogger mUiEventLogger = new UiEventLoggerImpl(); @Override - public void logNotificationReported(NotificationRecord r, NotificationRecord old, + public void maybeLogNotificationPosted(NotificationRecord r, NotificationRecord old, int position, int buzzBeepBlink) { NotificationRecordPair p = new NotificationRecordPair(r, old); - if (!p.shouldLog(buzzBeepBlink)) { + if (!p.shouldLogReported(buzzBeepBlink)) { return; } FrameworkStatsLog.write(FrameworkStatsLog.NOTIFICATION_REPORTED, @@ -66,8 +66,19 @@ public class NotificationRecordLoggerImpl implements NotificationRecordLogger { @Override public void logNotificationCancelled(NotificationRecord r, int reason, int dismissalSurface) { - mUiEventLogger.logWithInstanceId( - NotificationCancelledEvent.fromCancelReason(reason, dismissalSurface), - r.getUid(), r.getSbn().getPackageName(), r.getSbn().getInstanceId()); + log(NotificationCancelledEvent.fromCancelReason(reason, dismissalSurface), r); + } + + @Override + public void logNotificationVisibility(NotificationRecord r, boolean visible) { + log(NotificationEvent.fromVisibility(visible), r); + } + + void log(UiEventLogger.UiEventEnum event, NotificationRecord r) { + if (r == null) { + return; + } + mUiEventLogger.logWithInstanceId(event, r.getUid(), r.getSbn().getPackageName(), + r.getSbn().getInstanceId()); } } diff --git a/services/tests/uiservicestests/src/com/android/server/notification/NotificationManagerServiceTest.java b/services/tests/uiservicestests/src/com/android/server/notification/NotificationManagerServiceTest.java index a0f7f5b801eca..9ca4038918d50 100755 --- a/services/tests/uiservicestests/src/com/android/server/notification/NotificationManagerServiceTest.java +++ b/services/tests/uiservicestests/src/com/android/server/notification/NotificationManagerServiceTest.java @@ -51,8 +51,6 @@ import static android.os.Build.VERSION_CODES.P; import static android.os.UserHandle.USER_SYSTEM; import static android.service.notification.Adjustment.KEY_IMPORTANCE; import static android.service.notification.Adjustment.KEY_USER_SENTIMENT; -import static android.service.notification.NotificationListenerService.REASON_APP_CANCEL; -import static android.service.notification.NotificationListenerService.REASON_CANCEL; import static android.service.notification.NotificationListenerService.Ranking.USER_SENTIMENT_NEGATIVE; import static android.service.notification.NotificationListenerService.Ranking.USER_SENTIMENT_NEUTRAL; @@ -1144,14 +1142,15 @@ public class NotificationManagerServiceTest extends UiServiceTestCase { } @Test - public void testEnqueueNotificationWithTag_WritesExpectedLog() throws Exception { + public void testEnqueueNotificationWithTag_WritesExpectedLogs() throws Exception { final String tag = "testEnqueueNotificationWithTag_WritesExpectedLog"; mBinderService.enqueueNotificationWithTag(PKG, PKG, tag, 0, generateNotificationRecord(null).getNotification(), 0); waitForIdle(); assertEquals(1, mNotificationRecordLogger.getCalls().size()); + NotificationRecordLoggerFake.CallRecord call = mNotificationRecordLogger.get(0); - assertTrue(call.shouldLog); + assertTrue(call.shouldLogReported); assertEquals(NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED, call.event); assertNotNull(call.r); @@ -1161,7 +1160,6 @@ public class NotificationManagerServiceTest extends UiServiceTestCase { assertEquals(PKG, call.r.getSbn().getPackageName()); assertEquals(0, call.r.getSbn().getId()); assertEquals(tag, call.r.getSbn().getTag()); - assertNotNull(call.r.getSbn().getInstanceId()); assertEquals(0, call.getInstanceId()); // Fake instance IDs are assigned in order } @@ -1180,13 +1178,13 @@ public class NotificationManagerServiceTest extends UiServiceTestCase { waitForIdle(); assertEquals(2, mNotificationRecordLogger.getCalls().size()); - assertTrue(mNotificationRecordLogger.get(0).shouldLog); + assertTrue(mNotificationRecordLogger.get(0).shouldLogReported); assertEquals( NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED, mNotificationRecordLogger.get(0).event); assertEquals(0, mNotificationRecordLogger.get(0).getInstanceId()); - assertTrue(mNotificationRecordLogger.get(1).shouldLog); + assertTrue(mNotificationRecordLogger.get(1).shouldLogReported); assertEquals( NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_UPDATED, mNotificationRecordLogger.get(1).event); @@ -1195,16 +1193,37 @@ public class NotificationManagerServiceTest extends UiServiceTestCase { } @Test - public void testEnqueueNotificationWithTag_DoesNotLogOnMinorUpdates() throws Exception { - final String tag = "testEnqueueNotificationWithTag_DoesNotLogOnMinorUpdates"; + public void testEnqueueNotificationWithTag_DoesNotLogOnMinorUpdate() throws Exception { + final String tag = "testEnqueueNotificationWithTag_DoesNotLogOnMinorUpdate"; mBinderService.enqueueNotificationWithTag(PKG, PKG, tag, 0, generateNotificationRecord(null).getNotification(), 0); mBinderService.enqueueNotificationWithTag(PKG, PKG, tag, 0, generateNotificationRecord(null).getNotification(), 0); waitForIdle(); assertEquals(2, mNotificationRecordLogger.getCalls().size()); - assertTrue(mNotificationRecordLogger.get(0).shouldLog); - assertFalse(mNotificationRecordLogger.get(1).shouldLog); + assertTrue(mNotificationRecordLogger.get(0).shouldLogReported); + assertEquals( + NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED, + mNotificationRecordLogger.get(0).event); + assertFalse(mNotificationRecordLogger.get(1).shouldLogReported); + assertNull(mNotificationRecordLogger.get(1).event); + } + + @Test + public void testEnqueueNotificationWithTag_DoesNotLogOnTitleUpdate() throws Exception { + final String tag = "testEnqueueNotificationWithTag_DoesNotLogOnTitleUpdate"; + mBinderService.enqueueNotificationWithTag(PKG, PKG, tag, 0, + generateNotificationRecord(null).getNotification(), + 0); + final Notification notif = generateNotificationRecord(null).getNotification(); + notif.extras.putString(Notification.EXTRA_TITLE, "Changed title"); + mBinderService.enqueueNotificationWithTag(PKG, PKG, tag, 0, notif, 0); + waitForIdle(); + assertEquals(2, mNotificationRecordLogger.getCalls().size()); + assertEquals( + NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED, + mNotificationRecordLogger.get(0).event); + assertNull(mNotificationRecordLogger.get(1).event); } @Test @@ -1224,20 +1243,18 @@ public class NotificationManagerServiceTest extends UiServiceTestCase { assertEquals( NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED, mNotificationRecordLogger.get(0).event); - assertTrue(mNotificationRecordLogger.get(0).shouldLog); + assertTrue(mNotificationRecordLogger.get(0).shouldLogReported); assertEquals(0, mNotificationRecordLogger.get(0).getInstanceId()); - assertEquals(REASON_APP_CANCEL, mNotificationRecordLogger.get(1).reason); assertEquals( NotificationRecordLogger.NotificationCancelledEvent.NOTIFICATION_CANCEL_APP_CANCEL, mNotificationRecordLogger.get(1).event); - assertTrue(mNotificationRecordLogger.get(1).shouldLog); assertEquals(0, mNotificationRecordLogger.get(1).getInstanceId()); assertEquals( NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED, mNotificationRecordLogger.get(2).event); - assertTrue(mNotificationRecordLogger.get(2).shouldLog); + assertTrue(mNotificationRecordLogger.get(2).shouldLogReported); // New instance ID because notification was canceled before re-post assertEquals(1, mNotificationRecordLogger.get(2).getInstanceId()); } @@ -3396,11 +3413,9 @@ public class NotificationManagerServiceTest extends UiServiceTestCase { // so we only get the cancel notification. assertEquals(1, mNotificationRecordLogger.getCalls().size()); - assertEquals(REASON_CANCEL, mNotificationRecordLogger.get(0).reason); assertEquals( NotificationRecordLogger.NotificationCancelledEvent.NOTIFICATION_CANCEL_USER_AOD, mNotificationRecordLogger.get(0).event); - assertTrue(mNotificationRecordLogger.get(0).shouldLog); assertEquals(0, mNotificationRecordLogger.get(0).getInstanceId()); } @@ -4325,6 +4340,34 @@ public class NotificationManagerServiceTest extends UiServiceTestCase { verify(mAppUsageStats).reportInterruptiveNotification(anyString(), anyString(), anyInt()); } + @Test + public void testOnNotificationVisibilityChanged_triggersVisibilityLog() { + final NotificationRecord r = generateNotificationRecord( + mTestNotificationChannel, 1, null, true); + r.setTextChanged(true); + mService.addNotification(r); + + mService.mNotificationDelegate.onNotificationVisibilityChanged(new NotificationVisibility[] + {NotificationVisibility.obtain(r.getKey(), 1, 1, true)}, + new NotificationVisibility[]{}); + + assertEquals(1, mNotificationRecordLogger.getCalls().size()); + assertEquals(NotificationRecordLogger.NotificationEvent.NOTIFICATION_OPEN, + mNotificationRecordLogger.get(0).event); + assertEquals(0, mNotificationRecordLogger.get(0).getInstanceId()); + + mService.mNotificationDelegate.onNotificationVisibilityChanged( + new NotificationVisibility[]{}, + new NotificationVisibility[] + {NotificationVisibility.obtain(r.getKey(), 1, 1, true)} + ); + + assertEquals(2, mNotificationRecordLogger.getCalls().size()); + assertEquals(NotificationRecordLogger.NotificationEvent.NOTIFICATION_CLOSE, + mNotificationRecordLogger.get(1).event); + assertEquals(0, mNotificationRecordLogger.get(1).getInstanceId()); + } + @Test public void testSetNotificationsShownFromListener_triggersInterruptionUsageStat() throws RemoteException { diff --git a/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordLoggerFake.java b/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordLoggerFake.java index b120dbee03c59..2a17bae57c8e5 100644 --- a/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordLoggerFake.java +++ b/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordLoggerFake.java @@ -26,24 +26,26 @@ import java.util.List; */ class NotificationRecordLoggerFake implements NotificationRecordLogger { static class CallRecord extends NotificationRecordPair { - static final int INVALID = -1; - public int position = INVALID, buzzBeepBlink = INVALID, reason = INVALID; - public boolean shouldLog; public UiEventLogger.UiEventEnum event; + + // The following fields are only relevant to maybeLogNotificationPosted() calls. + static final int INVALID = -1; + public int position = INVALID, buzzBeepBlink = INVALID; + public boolean shouldLogReported; + CallRecord(NotificationRecord r, NotificationRecord old, int position, int buzzBeepBlink) { super(r, old); - this.position = position; this.buzzBeepBlink = buzzBeepBlink; - shouldLog = shouldLog(buzzBeepBlink); - event = NotificationReportedEvent.fromRecordPair(this); + shouldLogReported = shouldLogReported(buzzBeepBlink); + event = shouldLogReported ? NotificationReportedEvent.fromRecordPair(this) : null; } - CallRecord(NotificationRecord r, int reason, int dismissalSurface) { + + CallRecord(NotificationRecord r, UiEventLogger.UiEventEnum event) { super(r, null); - this.reason = reason; - shouldLog = true; - event = NotificationCancelledEvent.fromCancelReason(reason, dismissalSurface); + shouldLogReported = false; + this.event = event; } } private List mCalls = new ArrayList<>(); @@ -57,14 +59,19 @@ class NotificationRecordLoggerFake implements NotificationRecordLogger { } @Override - public void logNotificationReported(NotificationRecord r, NotificationRecord old, + public void maybeLogNotificationPosted(NotificationRecord r, NotificationRecord old, int position, int buzzBeepBlink) { mCalls.add(new CallRecord(r, old, position, buzzBeepBlink)); } @Override public void logNotificationCancelled(NotificationRecord r, int reason, int dismissalSurface) { - mCalls.add(new CallRecord(r, reason, dismissalSurface)); + mCalls.add(new CallRecord(r, + NotificationCancelledEvent.fromCancelReason(reason, dismissalSurface))); } + @Override + public void logNotificationVisibility(NotificationRecord r, boolean visible) { + mCalls.add(new CallRecord(r, NotificationEvent.fromVisibility(visible))); + } }