From 934b8e367432d18b244c106a845947876c71b6b8 Mon Sep 17 00:00:00 2001 From: Will Brockman Date: Fri, 8 Mar 2019 11:14:45 -0500 Subject: Add Tron logging of explanation for notification importance. Adds the results of CalculateImportance by default on notification logs, so that we can track the effects of NotificationAssistant and user and system importance overrides. Adds tests for the various different sources of importance. Bug: 127834982 Test: atest frameworks/base/services/tests/uiservicestests/src/com/android/server/notification SystemUITests Change-Id: I044d1206f5180a028bb55704ced05117bc0a00bb --- .../src/metrics_constants/metrics_constants.proto | 27 ++++ .../server/notification/NotificationRecord.java | 80 +++++++++--- .../notification/NotificationRecordTest.java | 137 ++++++++++++++++++++- 3 files changed, 225 insertions(+), 19 deletions(-) diff --git a/proto/src/metrics_constants/metrics_constants.proto b/proto/src/metrics_constants/metrics_constants.proto index 9673a84018e4..bc4286356ead 100644 --- a/proto/src/metrics_constants/metrics_constants.proto +++ b/proto/src/metrics_constants/metrics_constants.proto @@ -260,6 +260,18 @@ message MetricsEvent { PREVIOUSLY_VISIBLE = 2; } + // Explanations for notification importance, derived from + // NotificationRecord.mImportanceExplanation. + enum NotificationImportanceExplanation { + IMPORTANCE_EXPLANATION_UNKNOWN = 0; + IMPORTANCE_EXPLANATION_APP = 1; // App-specified channel importance. + IMPORTANCE_EXPLANATION_USER = 2; // User-specified channel importance. + IMPORTANCE_EXPLANATION_ASST = 3; // Notification Assistant override. + IMPORTANCE_EXPLANATION_SYSTEM = 4; // System override. + // Like _APP, but based on pre-channels priority signal. + IMPORTANCE_EXPLANATION_APP_PRE_CHANNELS = 5; + } + // Known visual elements: views or controls. enum View { // Unknown view @@ -7090,6 +7102,21 @@ message MetricsEvent { // Panel for Wifi PANEL_WIFI = 1687; + // Custom tag for NotificationItem. A NotificationImportanceExplanation. + FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION = 1688; + + // Custom tag for NotificationItem. The initial "natural" importance. + FIELD_NOTIFICATION_IMPORTANCE_INITIAL = 1689; + + // Custom tag for NotificationItem. A NotificationImportanceExplanation. + // The source of the "natural" importance, if it was overridden. + FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION = 1690; + + // Custom tag for NotificationItem. The Notification Assistant's + // override of importance. Logged separately only if it was + // overridden by the system. + FIELD_NOTIFICATION_IMPORTANCE_ASST = 1691; + // ---- End Q Constants, all Q constants go above this line ---- // Add new aosp constants above this line. // END OF AOSP CONSTANTS diff --git a/services/core/java/com/android/server/notification/NotificationRecord.java b/services/core/java/com/android/server/notification/NotificationRecord.java index 46ce4bf59a50..d9ab13295166 100644 --- a/services/core/java/com/android/server/notification/NotificationRecord.java +++ b/services/core/java/com/android/server/notification/NotificationRecord.java @@ -149,7 +149,10 @@ public final class NotificationRecord { private int mImportance = IMPORTANCE_UNSPECIFIED; // Field used in global sort key to bypass normal notifications private int mCriticality = CriticalNotificationExtractor.NORMAL; - private CharSequence mImportanceExplanation = null; + // A MetricsEvent.NotificationImportanceExplanation, tracking source of mImportance. + private int mImportanceExplanationCode = MetricsEvent.IMPORTANCE_EXPLANATION_UNKNOWN; + // A MetricsEvent.NotificationImportanceExplanation for initial importance. + private int mInitialImportanceExplanationCode = MetricsEvent.IMPORTANCE_EXPLANATION_UNKNOWN; private int mSuppressedVisualEffects = 0; private String mUserExplanation; @@ -332,14 +335,18 @@ public final class NotificationRecord { private int calculateInitialImportance() { final Notification n = sbn.getNotification(); - int importance = getChannel().getImportance(); - int requestedImportance = IMPORTANCE_DEFAULT; + int importance = getChannel().getImportance(); // Post-channels notifications use this + mInitialImportanceExplanationCode = getChannel().hasUserSetImportance() + ? MetricsEvent.IMPORTANCE_EXPLANATION_USER + : MetricsEvent.IMPORTANCE_EXPLANATION_APP; - // Migrate notification flags to scores + // Migrate notification priority flag to a priority value. if (0 != (n.flags & Notification.FLAG_HIGH_PRIORITY)) { n.priority = Notification.PRIORITY_MAX; } + // Convert priority value to an importance value, used only for pre-channels notifications. + int requestedImportance = IMPORTANCE_DEFAULT; n.priority = NotificationManagerService.clamp(n.priority, Notification.PRIORITY_MIN, Notification.PRIORITY_MAX); switch (n.priority) { @@ -360,10 +367,11 @@ public final class NotificationRecord { stats.requestedImportance = requestedImportance; stats.isNoisy = mSound != null || mVibration != null; + // For pre-channels notifications, apply system overrides and then use requestedImportance + // as importance. if (mPreChannelsNotification && (importance == IMPORTANCE_UNSPECIFIED - || (getChannel().getUserLockedFields() - & USER_LOCKED_IMPORTANCE) == 0)) { + || (!getChannel().hasUserSetImportance()))) { if (!stats.isNoisy && requestedImportance > IMPORTANCE_LOW) { requestedImportance = IMPORTANCE_LOW; } @@ -378,6 +386,8 @@ public final class NotificationRecord { requestedImportance = IMPORTANCE_HIGH; } importance = requestedImportance; + mInitialImportanceExplanationCode = + MetricsEvent.IMPORTANCE_EXPLANATION_APP_PRE_CHANNELS; } stats.naturalImportance = importance; @@ -540,7 +550,7 @@ public final class NotificationRecord { + NotificationListenerService.Ranking.importanceToString(mAssistantImportance)); pw.println(prefix + "mImportance=" + NotificationListenerService.Ranking.importanceToString(mImportance)); - pw.println(prefix + "mImportanceExplanation=" + mImportanceExplanation); + pw.println(prefix + "mImportanceExplanation=" + getImportanceExplanation()); pw.println(prefix + "mIsAppImportanceLocked=" + mIsAppImportanceLocked); pw.println(prefix + "mIntercept=" + mIntercept); pw.println(prefix + "mHidden==" + mHidden); @@ -760,23 +770,23 @@ public final class NotificationRecord { } /** - * Recalculates the importance of the record after fields affecting importance have changed + * Recalculates the importance of the record after fields affecting importance have changed, + * and records an explanation. */ protected void calculateImportance() { mImportance = calculateInitialImportance(); - mImportanceExplanation = "app"; - if (getChannel().hasUserSetImportance()) { - mImportanceExplanation = "user"; - } + mImportanceExplanationCode = mInitialImportanceExplanationCode; + + // Consider Notification Assistant and system overrides to importance. If both, system wins. if (!getChannel().hasUserSetImportance() && mAssistantImportance != IMPORTANCE_UNSPECIFIED && !getChannel().isImportanceLockedByOEM()) { mImportance = mAssistantImportance; - mImportanceExplanation = "asst"; + mImportanceExplanationCode = MetricsEvent.IMPORTANCE_EXPLANATION_ASST; } if (mSystemImportance != IMPORTANCE_UNSPECIFIED) { mImportance = mSystemImportance; - mImportanceExplanation = "system"; + mImportanceExplanationCode = MetricsEvent.IMPORTANCE_EXPLANATION_SYSTEM; } } @@ -785,7 +795,20 @@ public final class NotificationRecord { } public CharSequence getImportanceExplanation() { - return mImportanceExplanation; + switch (mImportanceExplanationCode) { + case MetricsEvent.IMPORTANCE_EXPLANATION_UNKNOWN: + return null; + case MetricsEvent.IMPORTANCE_EXPLANATION_APP: + case MetricsEvent.IMPORTANCE_EXPLANATION_APP_PRE_CHANNELS: + return "app"; + case MetricsEvent.IMPORTANCE_EXPLANATION_USER: + return "user"; + case MetricsEvent.IMPORTANCE_EXPLANATION_ASST: + return "asst"; + case MetricsEvent.IMPORTANCE_EXPLANATION_SYSTEM: + return "system"; + } + return null; } public boolean setIntercepted(boolean intercept) { @@ -1242,14 +1265,37 @@ public final class NotificationRecord { } public LogMaker getLogMaker(long now) { - return sbn.getLogMaker() - .clearTaggedData(MetricsEvent.NOTIFICATION_SHADE_INDEX) + LogMaker lm = sbn.getLogMaker() .addTaggedData(MetricsEvent.FIELD_NOTIFICATION_CHANNEL_IMPORTANCE, mImportance) .addTaggedData(MetricsEvent.NOTIFICATION_SINCE_CREATE_MILLIS, getLifespanMs(now)) .addTaggedData(MetricsEvent.NOTIFICATION_SINCE_UPDATE_MILLIS, getFreshnessMs(now)) .addTaggedData(MetricsEvent.NOTIFICATION_SINCE_VISIBLE_MILLIS, getExposureMs(now)) .addTaggedData(MetricsEvent.NOTIFICATION_SINCE_INTERRUPTION_MILLIS, getInterruptionMs(now)); + // Record results of the calculateImportance() calculation if available. + if (mImportanceExplanationCode != MetricsEvent.IMPORTANCE_EXPLANATION_UNKNOWN) { + lm.addTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION, + mImportanceExplanationCode); + // To avoid redundancy, we log the initial importance information only if it was + // overridden. + if (((mImportanceExplanationCode == MetricsEvent.IMPORTANCE_EXPLANATION_ASST) + || (mImportanceExplanationCode == MetricsEvent.IMPORTANCE_EXPLANATION_SYSTEM)) + && (stats.naturalImportance != IMPORTANCE_UNSPECIFIED)) { + // stats.naturalImportance is due to one of the 3 sources of initial importance. + lm.addTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION, + mInitialImportanceExplanationCode); + lm.addTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL, + stats.naturalImportance); + } + // Log Assistant override if it was itself overridden by System. Since System can't be + // overridden, it never needs logging. + if (mImportanceExplanationCode == MetricsEvent.IMPORTANCE_EXPLANATION_SYSTEM + && mAssistantImportance != IMPORTANCE_UNSPECIFIED) { + lm.addTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_ASST, + mAssistantImportance); + } + } + return lm; } public LogMaker getLogMaker() { diff --git a/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordTest.java b/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordTest.java index 9f11472b9c7c..e375195af5c9 100644 --- a/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordTest.java +++ b/services/tests/uiservicestests/src/com/android/server/notification/NotificationRecordTest.java @@ -19,6 +19,7 @@ import static android.app.NotificationChannel.USER_LOCKED_IMPORTANCE; import static android.app.NotificationManager.IMPORTANCE_DEFAULT; import static android.app.NotificationManager.IMPORTANCE_HIGH; import static android.app.NotificationManager.IMPORTANCE_LOW; +import static android.service.notification.Adjustment.KEY_IMPORTANCE; import static android.service.notification.NotificationListenerService.Ranking.USER_SENTIMENT_NEGATIVE; import static android.service.notification.NotificationListenerService.Ranking.USER_SENTIMENT_NEUTRAL; import static android.service.notification.NotificationListenerService.Ranking.USER_SENTIMENT_POSITIVE; @@ -423,6 +424,138 @@ public class NotificationRecordTest extends UiServiceTestCase { (int) logMaker.getTaggedData(MetricsEvent.NOTIFICATION_SINCE_VISIBLE_MILLIS)); assertEquals(record.getInterruptionMs(timestamp), (int) logMaker.getTaggedData(MetricsEvent.NOTIFICATION_SINCE_INTERRUPTION_MILLIS)); + // If no importance calculation has been run, no explanation is available. + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION)); + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL)); + assertNull(logMaker.getTaggedData( + MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION)); + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_ASST)); + } + + @Test + public void testLogMakerImportanceApp() { + long timestamp = 1000L; + StatusBarNotification sbn = getNotification(PKG_O, true /* noisy */, + true /* defaultSound */, false /* buzzy */, false /* defaultBuzz */, + false /* lights */, false /* defaultLights */, null /* group */); + NotificationRecord record = new NotificationRecord(mMockContext, sbn, channel); + + record.calculateImportance(); // This importance calculation will yield 'app' + final LogMaker logMaker = record.getLogMaker(timestamp); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_APP, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION)); + assertEquals(channel.getImportance(), + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_CHANNEL_IMPORTANCE)); + // The additional information is only populated if the initial importance is overridden. + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL)); + assertNull(logMaker.getTaggedData( + MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION)); + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_ASST)); + } + + @Test + public void testLogMakerImportanceAsst() { + long timestamp = 1000L; + StatusBarNotification sbn = getNotification(PKG_O, true /* noisy */, + true /* defaultSound */, false /* buzzy */, false /* defaultBuzz */, + false /* lights */, false /* defaultLights */, null /* group */); + NotificationRecord record = new NotificationRecord(mMockContext, sbn, channel); + Bundle signals = new Bundle(); + signals.putInt(KEY_IMPORTANCE, IMPORTANCE_LOW); + record.addAdjustment(new Adjustment(PKG_O, KEY_IMPORTANCE, signals, "", uid)); + record.applyAdjustments(); + record.calculateImportance(); // This importance calculation will yield 'asst' + final LogMaker logMaker = record.getLogMaker(timestamp); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_ASST, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION)); + // Therefore this is the assistant-set importance + assertEquals(IMPORTANCE_LOW, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_CHANNEL_IMPORTANCE)); + // Initial importance is populated so we know what it was, since it didn't get used. + assertEquals(channel.getImportance(), + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL)); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_APP, + logMaker.getTaggedData( + MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION)); + // This field is only populated if the assistant was itself overridden by the system. + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_ASST)); + } + + @Test + public void testLogMakerImportanceSystem() { + long timestamp = 1000L; + StatusBarNotification sbn = getNotification(PKG_O, true /* noisy */, + true /* defaultSound */, false /* buzzy */, false /* defaultBuzz */, + false /* lights */, false /* defaultLights */, null /* group */); + NotificationRecord record = new NotificationRecord(mMockContext, sbn, channel); + record.setSystemImportance(IMPORTANCE_HIGH); + record.calculateImportance(); // This importance calculation will yield 'system' + final LogMaker logMaker = record.getLogMaker(timestamp); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_SYSTEM, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION)); + // Therefore this is the system-set importance + assertEquals(IMPORTANCE_HIGH, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_CHANNEL_IMPORTANCE)); + // Initial importance is populated so we know what it was, since it didn't get used. + assertEquals(channel.getImportance(), + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL)); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_APP, + logMaker.getTaggedData( + MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION)); + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_ASST)); + } + + @Test + public void testLogMakerImportanceUser() { + long timestamp = 1000L; + channel.lockFields(channel.USER_LOCKED_IMPORTANCE); + StatusBarNotification sbn = getNotification(PKG_O, true /* noisy */, + true /* defaultSound */, false /* buzzy */, false /* defaultBuzz */, + false /* lights */, false /* defaultLights */, null /* group */); + NotificationRecord record = new NotificationRecord(mMockContext, sbn, channel); + record.calculateImportance(); // This importance calculation will yield 'user' + final LogMaker logMaker = record.getLogMaker(timestamp); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_USER, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION)); + // Therefore this is the user-set importance + assertEquals(channel.getImportance(), + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_CHANNEL_IMPORTANCE)); + // The additional information is only populated if the initial importance is overridden. + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL)); + assertNull(logMaker.getTaggedData( + MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION)); + assertNull(logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_ASST)); + } + + @Test + public void testLogMakerImportanceMulti() { + long timestamp = 1000L; + channel.lockFields(channel.USER_LOCKED_IMPORTANCE); + StatusBarNotification sbn = getNotification(PKG_O, true /* noisy */, + true /* defaultSound */, false /* buzzy */, false /* defaultBuzz */, + false /* lights */, false /* defaultLights */, null /* group */); + NotificationRecord record = new NotificationRecord(mMockContext, sbn, channel); + // Add all 3 ways of overriding the app-set importance of the notification + Bundle signals = new Bundle(); + signals.putInt(KEY_IMPORTANCE, IMPORTANCE_LOW); + record.addAdjustment(new Adjustment(PKG_O, KEY_IMPORTANCE, signals, "", uid)); + record.applyAdjustments(); + record.setSystemImportance(IMPORTANCE_HIGH); + record.calculateImportance(); // This importance calculation will yield 'system' + final LogMaker logMaker = record.getLogMaker(timestamp); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_SYSTEM, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_EXPLANATION)); + // Therefore this is the system-set importance + assertEquals(IMPORTANCE_HIGH, + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_CHANNEL_IMPORTANCE)); + // Initial importance is populated so we know what it was, since it didn't get used. + assertEquals(channel.getImportance(), + logMaker.getTaggedData(MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL)); + assertEquals(MetricsEvent.IMPORTANCE_EXPLANATION_USER, logMaker.getTaggedData( + MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_INITIAL_EXPLANATION)); + // Assistant importance is populated so we know what it was, since it didn't get used. + assertEquals(IMPORTANCE_LOW, logMaker.getTaggedData( + MetricsEvent.FIELD_NOTIFICATION_IMPORTANCE_ASST)); } @Test @@ -807,7 +940,7 @@ public class NotificationRecordTest extends UiServiceTestCase { assertEquals(IMPORTANCE_DEFAULT, record.getImportance()); Bundle bundle = new Bundle(); - bundle.putInt(Adjustment.KEY_IMPORTANCE, IMPORTANCE_LOW); + bundle.putInt(KEY_IMPORTANCE, IMPORTANCE_LOW); Adjustment adjustment = new Adjustment( PKG_O, record.getKey(), bundle, "", record.getUserId()); @@ -831,7 +964,7 @@ public class NotificationRecordTest extends UiServiceTestCase { assertEquals(IMPORTANCE_DEFAULT, record.getImportance()); Bundle bundle = new Bundle(); - bundle.putInt(Adjustment.KEY_IMPORTANCE, IMPORTANCE_LOW); + bundle.putInt(KEY_IMPORTANCE, IMPORTANCE_LOW); Adjustment adjustment = new Adjustment( PKG_O, record.getKey(), bundle, "", record.getUserId()); -- cgit v1.2.3-59-g8ed1b