Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 1df86542 authored by Matías Hernández's avatar Matías Hernández
Browse files

Log NotificationManager client throttling to statsd 

Because only system_server can log counters, we call into system_server to do it. This is itself rate-limited to once a second, so the performance impact should be negligible (and this logging won't make it to nextfood, regardless).

Also switched the logging limit to once per second, so that it matches our other metrics more closely.

Bug: 389918945
Test: atest NotificationManagerTest
Flag: android.app.nm_binder_perf_log_nm_throttling
Change-Id: I2b7961c3fe65fb461e80f7cec31cde1bb07a2e44
parent 054fdfda

core/java/android/app/INotificationManager.aidl

+3 −0
Original line number Diff line number Diff line
@@ -273,4 +273,7 @@ interface INotificationManager 
    void setAssistantAdjustmentKeyTypeState(int type, boolean enabled);

    String[] getTypeAdjustmentDeniedPackages();

    void setTypeAdjustmentForPackageState(String pkg, boolean enabled);



    // TODO: b/389918945 - Remove once nm_binder_perf flags are going to Nextfood.

    void incrementCounter(String metricId);

}

core/java/android/app/NotificationManager.java

+14 −2
Original line number Diff line number Diff line
@@ -665,8 +665,10 @@ public class NotificationManager { 


    private final InstantSource mClock;

    private final RateLimiter mUpdateRateLimiter = new RateLimiter("notify (update)",

            "notifications.value_client_throttled_notify_update",

            MAX_NOTIFICATION_UPDATE_RATE);

    private final RateLimiter mUnnecessaryCancelRateLimiter = new RateLimiter("cancel (dupe)",

            "notifications.value_client_throttled_cancel_duplicate",

            MAX_NOTIFICATION_UNNECESSARY_CANCEL_RATE);

    // Value is KNOWN_STATUS_ENQUEUED/_CANCELLED

    private final LruCache<NotificationKey, Integer> mKnownNotifications = new LruCache<>(100);
@@ -848,19 +850,21 @@ public class NotificationManager { 
    /** Helper class to rate-limit Binder calls. */

    private class RateLimiter {



        private static final Duration RATE_LIMITER_LOG_INTERVAL = Duration.ofSeconds(5);

        private static final Duration RATE_LIMITER_LOG_INTERVAL = Duration.ofSeconds(1);



        private final RateEstimator mInputRateEstimator;

        private final RateEstimator mOutputRateEstimator;

        private final String mName;

        private final String mCounterName;

        private final float mLimitRate;



        private Instant mLogSilencedUntil;



        private RateLimiter(String name, float limitRate) {

        private RateLimiter(String name, String counterName, float limitRate) {

            mInputRateEstimator = new RateEstimator();

            mOutputRateEstimator = new RateEstimator();

            mName = name;

            mCounterName = counterName;

            mLimitRate = limitRate;

        }
@@ -880,6 +884,14 @@ public class NotificationManager { 
                return;

            }



            if (Flags.nmBinderPerfLogNmThrottling()) {

                try {

                    service().incrementCounter(mCounterName);

                } catch (RemoteException e) {

                    Slog.w(TAG, "Ignoring error while trying to log " + mCounterName, e);

                }

            }



            long nowMillis = now.toEpochMilli();

            Slog.w(TAG, TextUtils.formatSimple(

                    "Shedding %s of %s, rate limit (%s) exceeded: input %s, output would be %s",

core/java/android/app/notification.aconfig

+10 −0
Original line number Diff line number Diff line
@@ -294,6 +294,16 @@ flag { 
  bug: "362981561"

}



flag {

  name: "nm_binder_perf_log_nm_throttling"

  namespace: "systemui"

  description: "Log throttled operations (notify, cancel) to statsd. This flag will NOT be pushed past Trunkfood."

  bug: "389918945"

  metadata {

    purpose: PURPOSE_BUGFIX

  }

}



flag {

  name: "no_sbnholder"

  namespace: "systemui"

core/tests/coretests/src/android/app/NotificationManagerTest.java

+32 −0
Original line number Diff line number Diff line
@@ -262,6 +262,38 @@ public class NotificationManagerTest { 
                anyInt(), any(), anyInt());

    }



    @Test

    @EnableFlags({Flags.FLAG_NM_BINDER_PERF_THROTTLE_NOTIFY,

            Flags.FLAG_NM_BINDER_PERF_LOG_NM_THROTTLING})

    public void notify_rapidUpdate_logsOncePerSecond() throws Exception {

        Notification n = exampleNotification();



        for (int i = 0; i < 650; i++) {

            mNotificationManager.notify(1, n);

            mClock.advanceByMillis(10);

        }



        // Runs for a total of 6.5 seconds, so should log once (when RateEstimator catches up) + 6

        // more times (after 1 second each).

        verify(mNotificationManager.mBackendService, times(7)).incrementCounter(

                eq("notifications.value_client_throttled_notify_update"));

    }



    @Test

    @EnableFlags({Flags.FLAG_NM_BINDER_PERF_THROTTLE_NOTIFY,

            Flags.FLAG_NM_BINDER_PERF_LOG_NM_THROTTLING})

    public void cancel_unnecessaryAndRapid_logsOncePerSecond() throws Exception {

        for (int i = 0; i < 650; i++) {

            mNotificationManager.cancel(1);

            mClock.advanceByMillis(10);

        }



        // Runs for a total of 6.5 seconds, so should log once (when RateEstimator catches up) + 6

        // more times (after 1 second each).

        verify(mNotificationManager.mBackendService, times(7)).incrementCounter(

                eq("notifications.value_client_throttled_cancel_duplicate"));

    }



    @Test

    @EnableFlags(Flags.FLAG_NM_BINDER_PERF_CACHE_CHANNELS)

    public void getNotificationChannel_cachedUntilInvalidated() throws Exception {

services/core/java/com/android/server/notification/NotificationManagerService.java

+8 −0
Original line number Diff line number Diff line
@@ -356,6 +356,7 @@ import com.android.internal.util.Preconditions; 
import com.android.internal.util.XmlUtils;

import com.android.internal.util.function.TriPredicate;

import com.android.internal.widget.LockPatternUtils;

import com.android.modules.expresslog.Counter;

import com.android.modules.utils.TypedXmlPullParser;

import com.android.modules.utils.TypedXmlSerializer;

import com.android.server.DeviceIdleInternal;
@@ -7136,6 +7137,13 @@ public class NotificationManagerService extends SystemService { 
            Slog.e(TAG, "exiting pullStats: bad request");

            return 0;

        }













        @Override













        public void incrementCounter(String metricId) {













            if (android.app.Flags.nmBinderPerfLogNmThrottling() && metricId != null) {













                Counter.logIncrementWithUid(metricId, Binder.getCallingUid());













            }













        }















    };





























    private void handleNotificationPermissionChange(String pkg, @UserIdInt int userId) {