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
This commit is contained in:
Will Brockman
2020-02-10 19:43:03 -05:00
parent e5bbdcfcf5
commit d3d49337e5
6 changed files with 134 additions and 43 deletions

View File

@@ -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();

View File

@@ -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);
}
/**

View File

@@ -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;
}

View File

@@ -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());
}
}

View File

@@ -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 {

View File

@@ -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<CallRecord> 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)));
}
}