Merge "Prepare to log post_duration_millis to statsd" into udc-dev am: d6c040c7b2

Original change: https://googleplex-android-review.googlesource.com/c/platform/frameworks/base/+/23114956

Change-Id: Ib24d42cac6b10ead4e5685b7094e4311655cd1b2
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
This commit is contained in:
Treehugger Robot
2023-05-10 13:39:07 +00:00
committed by Automerger Merge Worker
4 changed files with 53 additions and 41 deletions

View File

@@ -136,6 +136,7 @@ import static com.android.server.utils.PriorityDump.PRIORITY_ARG_NORMAL;
import android.Manifest;
import android.Manifest.permission;
import android.annotation.DurationMillisLong;
import android.annotation.ElapsedRealtimeLong;
import android.annotation.MainThread;
import android.annotation.NonNull;
@@ -7872,11 +7873,11 @@ public class NotificationManagerService extends SystemService {
}
if (notification.getSmallIcon() != null) {
mTracker.setReport(
NotificationRecordLogger.NotificationReported maybeReport =
mNotificationRecordLogger.prepareToLogNotificationPosted(r, old,
position, buzzBeepBlinkLoggingCode,
getGroupInstanceId(r.getSbn().getGroupKey())));
notifyListenersPostedAndLogLocked(r, old, mTracker);
getGroupInstanceId(r.getSbn().getGroupKey()));
notifyListenersPostedAndLogLocked(r, old, mTracker, maybeReport);
posted = true;
StatusBarNotification oldSbn = (old != null) ? old.getSbn() : null;
@@ -10860,16 +10861,17 @@ public class NotificationManagerService extends SystemService {
*/
@GuardedBy("mNotificationLock")
private void notifyListenersPostedAndLogLocked(NotificationRecord r, NotificationRecord old,
@NonNull PostNotificationTracker tracker) {
@NonNull PostNotificationTracker tracker,
@Nullable NotificationRecordLogger.NotificationReported report) {
List<Runnable> listenerCalls = mListeners.prepareNotifyPostedLocked(r, old, true);
mHandler.post(() -> {
for (Runnable listenerCall : listenerCalls) {
listenerCall.run();
}
tracker.finish();
NotificationRecordLogger.NotificationReported report = tracker.getReport();
long postDurationMillis = tracker.finish();
if (report != null) {
report.post_duration_millis = postDurationMillis;
mNotificationRecordLogger.logNotificationPosted(report);
}
});
@@ -12161,14 +12163,6 @@ public class NotificationManagerService extends SystemService {
}
}
void setReport(@Nullable NotificationRecordLogger.NotificationReported report) {
mReport = report;
}
NotificationRecordLogger.NotificationReported getReport() {
return mReport;
}
@ElapsedRealtimeLong
long getStartTime() {
return mStartTime;
@@ -12179,6 +12173,11 @@ public class NotificationManagerService extends SystemService {
return mOngoing;
}
/**
* Cancels the tracker (TODO(b/275044361): releasing the acquired WakeLock). Either
* {@link #finish} or {@link #cancel} (exclusively) should be called on this object before
* it's discarded.
*/
void cancel() {
if (!isOngoing()) {
Log.wtfStack(TAG, "cancel() called on already-finished tracker");
@@ -12195,20 +12194,27 @@ public class NotificationManagerService extends SystemService {
}
}
void finish() {
/**
* Finishes the tracker (TODO(b/275044361): releasing the acquired WakeLock) and returns the
* time elapsed since the operation started, in milliseconds. Either {@link #finish} or
* {@link #cancel} (exclusively) should be called on this object before it's discarded.
*/
@DurationMillisLong
long finish() {
long elapsedTime = SystemClock.elapsedRealtime() - mStartTime;
if (!isOngoing()) {
Log.wtfStack(TAG, "finish() called on already-finished tracker");
return;
return elapsedTime;
}
mOngoing = false;
// TODO(b/275044361): Release wakelock.
long elapsedTime = SystemClock.elapsedRealtime() - mStartTime;
if (DBG) {
Slog.d(TAG,
TextUtils.formatSimple("PostNotification: Finished in %d ms", elapsedTime));
}
return elapsedTime;
}
}
}

View File

@@ -21,6 +21,7 @@ import static android.service.notification.NotificationListenerService.REASON_CA
import static android.service.notification.NotificationListenerService.REASON_CLEAR_DATA;
import static android.service.notification.NotificationListenerService.REASON_CLICK;
import android.annotation.DurationMillisLong;
import android.annotation.NonNull;
import android.annotation.Nullable;
import android.app.Notification;
@@ -499,6 +500,7 @@ interface NotificationRecordLogger {
final boolean is_foreground_service;
final long timeout_millis;
final boolean is_non_dismissible;
@DurationMillisLong long post_duration_millis; // Not final; calculated at the end.
NotificationReported(NotificationRecordPair p,
NotificationReportedEvent eventType, int position, int buzzBeepBlink,

View File

@@ -81,6 +81,9 @@ import static com.android.internal.config.sysui.SystemUiSystemPropertiesFlags.No
import static com.android.internal.config.sysui.SystemUiSystemPropertiesFlags.NotificationFlags.FSI_FORCE_DEMOTE;
import static com.android.internal.config.sysui.SystemUiSystemPropertiesFlags.NotificationFlags.SHOW_STICKY_HUN_FOR_DENIED_FSI;
import static com.android.internal.widget.LockPatternUtils.StrongAuthTracker.STRONG_AUTH_REQUIRED_AFTER_USER_LOCKDOWN;
import static com.android.server.notification.NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_ADJUSTED;
import static com.android.server.notification.NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED;
import static com.android.server.notification.NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_UPDATED;
import static com.google.common.truth.Truth.assertThat;
import static com.google.common.truth.Truth.assertWithMessage;
@@ -663,6 +666,11 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
for (NotificationRecordLoggerFake.CallRecord call : mNotificationRecordLogger.getCalls()) {
if (call.wasLogged) {
assertNotNull(call.event);
if (call.event == NOTIFICATION_POSTED || call.event == NOTIFICATION_UPDATED) {
assertThat(call.postDurationMillisLogged).isGreaterThan(0);
} else {
assertThat(call.postDurationMillisLogged).isNull();
}
}
}
assertThat(mNotificationRecordLogger.getPendingLogs()).isEmpty();
@@ -1564,8 +1572,7 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
NotificationRecordLoggerFake.CallRecord call = mNotificationRecordLogger.get(0);
assertTrue(call.wasLogged);
assertEquals(NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED,
call.event);
assertEquals(NOTIFICATION_POSTED, call.event);
assertNotNull(call.r);
assertNull(call.old);
assertEquals(0, call.position);
@@ -1574,6 +1581,7 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
assertEquals(0, call.r.getSbn().getId());
assertEquals(tag, call.r.getSbn().getTag());
assertEquals(1, call.getInstanceId()); // Fake instance IDs are assigned in order
assertThat(call.postDurationMillisLogged).isGreaterThan(0);
}
@Test
@@ -1592,17 +1600,15 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
assertEquals(2, mNotificationRecordLogger.numCalls());
assertTrue(mNotificationRecordLogger.get(0).wasLogged);
assertEquals(
NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED,
mNotificationRecordLogger.event(0));
assertEquals(NOTIFICATION_POSTED, mNotificationRecordLogger.event(0));
assertEquals(1, mNotificationRecordLogger.get(0).getInstanceId());
assertThat(mNotificationRecordLogger.get(0).postDurationMillisLogged).isGreaterThan(0);
assertTrue(mNotificationRecordLogger.get(1).wasLogged);
assertEquals(
NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_UPDATED,
mNotificationRecordLogger.event(1));
assertEquals(NOTIFICATION_UPDATED, mNotificationRecordLogger.event(1));
// Instance ID doesn't change on update of an active notification
assertEquals(1, mNotificationRecordLogger.get(1).getInstanceId());
assertThat(mNotificationRecordLogger.get(1).postDurationMillisLogged).isGreaterThan(0);
}
@Test
@@ -1615,9 +1621,7 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
waitForIdle();
assertEquals(2, mNotificationRecordLogger.numCalls());
assertTrue(mNotificationRecordLogger.get(0).wasLogged);
assertEquals(
NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED,
mNotificationRecordLogger.event(0));
assertEquals(NOTIFICATION_POSTED, mNotificationRecordLogger.event(0));
assertFalse(mNotificationRecordLogger.get(1).wasLogged);
assertNull(mNotificationRecordLogger.event(1));
}
@@ -1633,9 +1637,7 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
mBinderService.enqueueNotificationWithTag(PKG, PKG, tag, 0, notif, 0);
waitForIdle();
assertEquals(2, mNotificationRecordLogger.numCalls());
assertEquals(
NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED,
mNotificationRecordLogger.event(0));
assertEquals(NOTIFICATION_POSTED, mNotificationRecordLogger.event(0));
assertNull(mNotificationRecordLogger.event(1));
}
@@ -1653,23 +1655,23 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
waitForIdle();
assertEquals(3, mNotificationRecordLogger.numCalls());
assertEquals(
NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED,
mNotificationRecordLogger.event(0));
assertEquals(NOTIFICATION_POSTED, mNotificationRecordLogger.event(0));
assertTrue(mNotificationRecordLogger.get(0).wasLogged);
assertEquals(1, mNotificationRecordLogger.get(0).getInstanceId());
assertThat(mNotificationRecordLogger.get(0).postDurationMillisLogged).isGreaterThan(0);
assertEquals(
NotificationRecordLogger.NotificationCancelledEvent.NOTIFICATION_CANCEL_APP_CANCEL,
mNotificationRecordLogger.event(1));
assertEquals(1, mNotificationRecordLogger.get(1).getInstanceId());
// Cancel is not post, so no logged post_duration_millis.
assertThat(mNotificationRecordLogger.get(1).postDurationMillisLogged).isNull();
assertEquals(
NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_POSTED,
mNotificationRecordLogger.event(2));
assertEquals(NOTIFICATION_POSTED, mNotificationRecordLogger.event(2));
assertTrue(mNotificationRecordLogger.get(2).wasLogged);
// New instance ID because notification was canceled before re-post
assertEquals(2, mNotificationRecordLogger.get(2).getInstanceId());
assertThat(mNotificationRecordLogger.get(2).postDurationMillisLogged).isGreaterThan(0);
}
@Test
@@ -5315,10 +5317,8 @@ public class NotificationManagerServiceTest extends UiServiceTestCase {
assertEquals(IMPORTANCE_HIGH, r1.getImportance());
assertTrue(r2.rankingScoreMatches(-0.5f));
assertEquals(2, mNotificationRecordLogger.numCalls());
assertEquals(NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_ADJUSTED,
mNotificationRecordLogger.event(0));
assertEquals(NotificationRecordLogger.NotificationReportedEvent.NOTIFICATION_ADJUSTED,
mNotificationRecordLogger.event(1));
assertEquals(NOTIFICATION_ADJUSTED, mNotificationRecordLogger.event(0));
assertEquals(NOTIFICATION_ADJUSTED, mNotificationRecordLogger.event(1));
assertEquals(1, mNotificationRecordLogger.get(0).getInstanceId());
assertEquals(2, mNotificationRecordLogger.get(1).getInstanceId());
}

View File

@@ -16,6 +16,8 @@
package com.android.server.notification;
import android.annotation.DurationMillisLong;
import androidx.annotation.Nullable;
import com.android.internal.logging.InstanceId;
@@ -38,6 +40,7 @@ class NotificationRecordLoggerFake implements NotificationRecordLogger {
public int position = INVALID, buzzBeepBlink = INVALID;
public boolean wasLogged;
public InstanceId groupInstanceId;
@Nullable @DurationMillisLong public Long postDurationMillisLogged;
CallRecord(NotificationRecord r, NotificationRecord old, int position,
int buzzBeepBlink, InstanceId groupId) {
@@ -111,6 +114,7 @@ class NotificationRecordLoggerFake implements NotificationRecordLogger {
}
mPendingLogs.remove(nr);
callRecord.wasLogged = true;
callRecord.postDurationMillisLogged = nr.post_duration_millis;
}
@Override