Merge "rate limit notification enqueues" into nyc-dev

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

@@ -92,6 +92,7 @@ import android.os.Looper;
 import android.os.Message;
 import android.os.Process;
 import android.os.RemoteException;
+import android.os.SystemClock;
 import android.os.SystemProperties;
 import android.os.UserHandle;
 import android.os.UserManager;
@@ -174,6 +175,7 @@ public class NotificationManagerService extends SystemService {
             = SystemProperties.getBoolean("debug.child_notifs", true);
 
     static final int MAX_PACKAGE_NOTIFICATIONS = 50;
+    static final float MAX_PACKAGE_ENQUEUE_RATE = 50f;
 
     // message codes
     static final int MESSAGE_TIMEOUT = 2;
@@ -216,6 +218,7 @@ public class NotificationManagerService extends SystemService {
 
     /** notification_enqueue status value for an ignored notification. */
     private static final int EVENTLOG_ENQUEUE_STATUS_IGNORED = 2;
+    private static final long MIN_PACKAGE_OVERRATE_LOG_INTERVAL = 5000; // milliseconds
     private String mRankerServicePackageName;
 
     private IActivityManager mAm;
@@ -295,6 +298,7 @@ public class NotificationManagerService extends SystemService {
     private static final int MY_UID = Process.myUid();
     private static final int MY_PID = Process.myPid();
     private RankingHandler mRankingHandler;
+    private long mLastOverRateLogTime;
 
     private static class Archive {
         final int mBufferSize;
@@ -2500,6 +2504,18 @@ public class NotificationManagerService extends SystemService {
         // package or a registered listener can enqueue.  Prevents DOS attacks and deals with leaks.
         if (!isSystemNotification && !isNotificationFromListener) {
             synchronized (mNotificationList) {
+                final float appEnqueueRate = mUsageStats.getAppEnqueueRate(pkg);
+                if (appEnqueueRate > MAX_PACKAGE_ENQUEUE_RATE) {
+                    mUsageStats.registerOverRateQuota(pkg);
+                    final long now = SystemClock.elapsedRealtime();
+                    if ((now - mLastOverRateLogTime) > MIN_PACKAGE_OVERRATE_LOG_INTERVAL) {
+                        Slog.e(TAG, "Package enqueue rate is " + appEnqueueRate
+                                + ". Shedding events. package=" + pkg);
+                        mLastOverRateLogTime = now;
+                    }
+                    return;
+                }
+
                 int count = 0;
                 final int N = mNotificationList.size();
                 for (int i=0; i<N; i++) {
@@ -2510,6 +2526,7 @@ public class NotificationManagerService extends SystemService {
                         }
                         count++;
                         if (count >= MAX_PACKAGE_NOTIFICATIONS) {
+                            mUsageStats.registerOverCountQuota(pkg);
                             Slog.e(TAG, "Package has already posted " + count
                                     + " notifications.  Not showing more.  package=" + pkg);
                             return;

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

@@ -29,6 +29,7 @@ import android.os.HandlerThread;
 import android.os.Message;
 import android.os.SystemClock;
 import android.text.TextUtils;
+import android.util.ArraySet;
 import android.util.Log;
 
 import com.android.internal.logging.MetricsLogger;
@@ -74,6 +75,7 @@ public class NotificationUsageStats {
     // Guarded by synchronized(this).
     private final Map<String, AggregatedStats> mStats = new HashMap<>();
     private final ArrayDeque<AggregatedStats[]> mStatsArrays = new ArrayDeque<>();
+    private ArraySet<String> mStatExpiredkeys = new ArraySet<>();
     private final SQLiteLog mSQLiteLog;
     private final Context mContext;
     private final Handler mHandler;
@@ -99,15 +101,29 @@ public class NotificationUsageStats {
         mHandler.sendEmptyMessageDelayed(MSG_EMIT, EMIT_PERIOD);
     }
 
+    /**
+     * Called when a notification has been posted.
+     */
+    public synchronized float getAppEnqueueRate(String packageName) {
+        AggregatedStats stats = getOrCreateAggregatedStatsLocked(packageName);
+        if (stats != null) {
+            return stats.getEnqueueRate(SystemClock.elapsedRealtime());
+        } else {
+            return 0f;
+        }
+    }
+
     /**
      * Called when a notification has been posted.
      */
     public synchronized void registerPostedByApp(NotificationRecord notification) {
-        notification.stats.posttimeElapsedMs = SystemClock.elapsedRealtime();
+        final long now = SystemClock.elapsedRealtime();
+        notification.stats.posttimeElapsedMs = now;
 
         AggregatedStats[] aggregatedStatsArray = getAggregatedStatsLocked(notification);
         for (AggregatedStats stats : aggregatedStatsArray) {
             stats.numPostedByApp++;
+            stats.updateInterarrivalEstimate(now);
             stats.countApiUse(notification);
         }
         releaseAggregatedStatsLocked(aggregatedStatsArray);
@@ -124,6 +140,7 @@ public class NotificationUsageStats {
         AggregatedStats[] aggregatedStatsArray = getAggregatedStatsLocked(notification);
         for (AggregatedStats stats : aggregatedStatsArray) {
             stats.numUpdatedByApp++;
+            stats.updateInterarrivalEstimate(SystemClock.elapsedRealtime());
             stats.countApiUse(notification);
         }
         releaseAggregatedStatsLocked(aggregatedStatsArray);
@@ -206,18 +223,37 @@ public class NotificationUsageStats {
         releaseAggregatedStatsLocked(aggregatedStatsArray);
     }
 
+    public synchronized void registerOverRateQuota(String packageName) {
+        AggregatedStats[] aggregatedStatsArray = getAggregatedStatsLocked(packageName);
+        for (AggregatedStats stats : aggregatedStatsArray) {
+            stats.numRateViolations++;
+        }
+    }
+
+    public synchronized void registerOverCountQuota(String packageName) {
+        AggregatedStats[] aggregatedStatsArray = getAggregatedStatsLocked(packageName);
+        for (AggregatedStats stats : aggregatedStatsArray) {
+            stats.numQuotaViolations++;
+        }
+    }
+
     // Locked by this.
     private AggregatedStats[] getAggregatedStatsLocked(NotificationRecord record) {
+        return getAggregatedStatsLocked(record.sbn.getPackageName());
+    }
+
+    // Locked by this.
+    private AggregatedStats[] getAggregatedStatsLocked(String packageName) {
         if (!ENABLE_AGGREGATED_IN_MEMORY_STATS) {
             return EMPTY_AGGREGATED_STATS;
         }
 
-        // TODO: expand to package-level counts in the future.
         AggregatedStats[] array = mStatsArrays.poll();
         if (array == null) {
-            array = new AggregatedStats[1];
+            array = new AggregatedStats[2];
         }
         array[0] = getOrCreateAggregatedStatsLocked(DEVICE_GLOBAL_STATS);
+        array[1] = getOrCreateAggregatedStatsLocked(packageName);
         return array;
     }
 
@@ -236,6 +272,7 @@ public class NotificationUsageStats {
             result = new AggregatedStats(mContext, key);
             mStats.put(key, result);
         }
+        result.mLastAccessTime = SystemClock.elapsedRealtime();
         return result;
     }
 
@@ -272,6 +309,7 @@ public class NotificationUsageStats {
                 as.dump(pw, indent);
             }
             pw.println(indent + "mStatsArrays.size(): " + mStatsArrays.size());
+            pw.println(indent + "mStats.size(): " + mStats.size());
         }
         if (ENABLE_SQLITE_LOG) {
             mSQLiteLog.dump(pw, indent, filter);
@@ -279,12 +317,20 @@ public class NotificationUsageStats {
     }
 
     public synchronized void emit() {
-        // TODO: expand to package-level counts in the future.
         AggregatedStats stats = getOrCreateAggregatedStatsLocked(DEVICE_GLOBAL_STATS);
         stats.emit();
-        mLastEmitTime = SystemClock.elapsedRealtime();
         mHandler.removeMessages(MSG_EMIT);
         mHandler.sendEmptyMessageDelayed(MSG_EMIT, EMIT_PERIOD);
+        for(String key: mStats.keySet()) {
+            if (mStats.get(key).mLastAccessTime < mLastEmitTime) {
+                mStatExpiredkeys.add(key);
+            }
+        }
+        for(String key: mStatExpiredkeys) {
+            mStats.remove(key);
+        }
+        mStatExpiredkeys.clear();
+        mLastEmitTime = SystemClock.elapsedRealtime();
     }
 
     /**
@@ -326,6 +372,10 @@ public class NotificationUsageStats {
         public ImportanceHistogram noisyImportance;
         public ImportanceHistogram quietImportance;
         public ImportanceHistogram finalImportance;
+        public RateEstimator enqueueRate;
+        public int numRateViolations;
+        public int numQuotaViolations;
+        public long mLastAccessTime;
 
         public AggregatedStats(Context context, String key) {
             this.key = key;
@@ -334,6 +384,7 @@ public class NotificationUsageStats {
             noisyImportance = new ImportanceHistogram(context, "note_imp_noisy_");
             quietImportance = new ImportanceHistogram(context, "note_imp_quiet_");
             finalImportance = new ImportanceHistogram(context, "note_importance_");
+            enqueueRate = new RateEstimator(mCreated);
         }
 
         public AggregatedStats getPrevious() {
@@ -444,6 +495,8 @@ public class NotificationUsageStats {
             maybeCount("note_text", (numWithText - previous.numWithText));
             maybeCount("note_sub_text", (numWithSubText - previous.numWithSubText));
             maybeCount("note_info_text", (numWithInfoText - previous.numWithInfoText));
+            maybeCount("note_over_rate", (numRateViolations - previous.numRateViolations));
+            maybeCount("note_over_quota", (numQuotaViolations - previous.numQuotaViolations));
             noisyImportance.maybeCount(previous.noisyImportance);
             quietImportance.maybeCount(previous.quietImportance);
             finalImportance.maybeCount(previous.finalImportance);
@@ -473,6 +526,8 @@ public class NotificationUsageStats {
             previous.numWithText = numWithText;
             previous.numWithSubText = numWithSubText;
             previous.numWithInfoText = numWithInfoText;
+            previous.numRateViolations = numRateViolations;
+            previous.numQuotaViolations = numQuotaViolations;
             noisyImportance.update(previous.noisyImportance);
             quietImportance.update(previous.quietImportance);
             finalImportance.update(previous.finalImportance);
@@ -493,6 +548,19 @@ public class NotificationUsageStats {
             return toStringWithIndent("");
         }
 
+        /** @return the enqueue rate if there were a new enqueue event right now. */
+        public float getEnqueueRate() {
+            return getEnqueueRate(SystemClock.elapsedRealtime());
+        }
+
+        public float getEnqueueRate(long now) {
+            return enqueueRate.getRate(now);
+        }
+
+        public void updateInterarrivalEstimate(long now) {
+            enqueueRate.update(now);
+        }
+
         private String toStringWithIndent(String indent) {
             StringBuilder output = new StringBuilder();
             output.append(indent).append("AggregatedStats{\n");
@@ -549,6 +617,8 @@ public class NotificationUsageStats {
             output.append("numWithSubText=").append(numWithSubText).append("\n");
             output.append(indentPlusTwo);
             output.append("numWithInfoText=").append(numWithInfoText).append("\n");
+            output.append("numRateViolations=").append(numRateViolations).append("\n");
+            output.append("numQuotaViolations=").append(numQuotaViolations).append("\n");
             output.append(indentPlusTwo).append(noisyImportance.toString()).append("\n");
             output.append(indentPlusTwo).append(quietImportance.toString()).append("\n");
             output.append(indentPlusTwo).append(finalImportance.toString()).append("\n");
@@ -586,6 +656,9 @@ public class NotificationUsageStats {
             maybePut(dump, "numWithText", numWithText);
             maybePut(dump, "numWithSubText", numWithSubText);
             maybePut(dump, "numWithInfoText", numWithInfoText);
+            maybePut(dump, "numRateViolations", numRateViolations);
+            maybePut(dump, "numQuotaLViolations", numQuotaViolations);
+            maybePut(dump, "notificationEnqueueRate", getEnqueueRate());
             noisyImportance.maybePut(dump, previous.noisyImportance);
             quietImportance.maybePut(dump, previous.quietImportance);
             finalImportance.maybePut(dump, previous.finalImportance);
@@ -598,6 +671,12 @@ public class NotificationUsageStats {
                 dump.put(name, value);
             }
         }
+
+        private void maybePut(JSONObject dump, String name, float value) throws JSONException {
+            if (value > 0.0) {
+                dump.put(name, value);
+            }
+        }
     }
 
     private static class ImportanceHistogram {

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

@@ -0,0 +1,54 @@
+/*
+ * Copyright (C) 2016 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License
+ */
+
+package com.android.server.notification;
+
+
+/**
+ * Exponentially weighted moving average estimator for event rate.
+ *
+ * {@hide}
+ */
+public class RateEstimator {
+    private static final double RATE_ALPHA = 0.8;
+    private static final double MINIMUM_DT = 0.0005;
+    private long mLastEventTime;
+    private float mInterarrivalTime;
+
+    public RateEstimator(long now) {
+        mLastEventTime = now;
+    }
+
+    /** Update the estimate to account for an event that jsut happened. */
+    public float update(long now) {
+        mInterarrivalTime = (float) getInterarrivalEstimate(now);
+        mLastEventTime = now;
+        return (float) (1.0 / mInterarrivalTime);
+    }
+
+    /** @return the estimated rate if there were a new event right now. */
+    public float getRate(long now) {
+        return (float) (1.0 / getInterarrivalEstimate(now));
+    }
+
+    /** @return the average inter-arrival time if there were a new event right now. */
+    private double getInterarrivalEstimate(long now) {
+        // a*iat_old + (1-a)*(t_now-t_last)
+        double dt = ((double) (now - mLastEventTime)) / 1000.0;
+        dt = Math.max(dt, MINIMUM_DT);
+        return (RATE_ALPHA * mInterarrivalTime + (1.0 - RATE_ALPHA) * dt);
+    }
+}

services/tests/servicestests/src/com/android/server/notification/RateEstimatorTest.java

@@ -0,0 +1,118 @@
+/*
+ * Copyright (C) 2016 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package com.android.server.notification;
+
+
+import android.test.AndroidTestCase;
+import android.test.suitebuilder.annotation.SmallTest;
+
+public class RateEstimatorTest extends AndroidTestCase {
+    private long mTestStartTime;
+    private RateEstimator mEstimator;
+
+    @Override
+    public void setUp() {
+        mTestStartTime = 1225731600000L;
+        mEstimator = new RateEstimator(mTestStartTime);
+    }
+
+    @SmallTest
+    public void testRunningTimeBackwardDoesntExplodeUpdate() throws Exception {
+        final float rate = mEstimator.update(mTestStartTime - 1000L);
+        assertFalse(Float.isInfinite(rate));
+        assertFalse(Float.isNaN(rate));
+    }
+
+    @SmallTest
+    public void testRunningTimeBackwardDoesntExplodeGet() throws Exception {
+        final float rate = mEstimator.getRate(mTestStartTime - 1000L);
+        assertFalse(Float.isInfinite(rate));
+        assertFalse(Float.isNaN(rate));
+    }
+
+    @SmallTest
+    public void testInstantaneousEventsDontExplodeUpdate() throws Exception {
+        final float rate = mEstimator.update(mTestStartTime);
+        assertFalse(Float.isInfinite(rate));
+        assertFalse(Float.isNaN(rate));
+    }
+
+    @SmallTest
+    public void testInstantaneousEventsDontExplodeGet() throws Exception {
+        final float rate = mEstimator.getRate(mTestStartTime);
+        assertFalse(Float.isInfinite(rate));
+        assertFalse(Float.isNaN(rate));
+    }
+
+    @SmallTest
+    public void testCompactBurstIsEstimatedUnderTwoPercent() throws Exception {
+        long eventStart = mTestStartTime + 1000; // start event a long time after initialization
+        long nextEventTime = postEvents(eventStart, 1, 5); // five events at 1000Hz
+        final float rate = mEstimator.getRate(nextEventTime);
+        assertLessThan("Rate", rate, 20f);
+    }
+
+    @SmallTest
+    public void testSustained1000HzBurstIsEstimatedOverNinetyPercent() throws Exception {
+        long eventStart = mTestStartTime + 1000; // start event a long time after initialization
+        long nextEventTime = postEvents(eventStart, 1, 100); // one hundred events at 1000Hz
+        final float rate = mEstimator.getRate(nextEventTime);
+        assertGreaterThan("Rate", rate, 900f);
+    }
+
+    @SmallTest
+    public void testSustained100HzBurstIsEstimatedOverNinetyPercent() throws Exception {
+        long eventStart = mTestStartTime + 1000; // start event a long time after initialization
+        long nextEventTime = postEvents(eventStart, 10, 100); // one hundred events at 100Hz
+        final float rate = mEstimator.getRate(nextEventTime);
+
+        assertGreaterThan("Rate", rate, 90f);
+    }
+
+    @SmallTest
+    public void testRecoverQuicklyAfterSustainedBurst() throws Exception {
+        long eventStart = mTestStartTime + 1000; // start event a long time after initialization
+        long nextEventTime = postEvents(eventStart, 10, 1000); // one hundred events at 100Hz
+        final float rate = mEstimator.getRate(nextEventTime + 5000L); // two seconds later
+        assertLessThan("Rate", rate, 2f);
+    }
+
+    @SmallTest
+    public void testEstimateShouldNotOvershoot() throws Exception {
+        long eventStart = mTestStartTime + 1000; // start event a long time after initialization
+        long nextEventTime = postEvents(eventStart, 1, 1000); // one thousand events at 1000Hz
+        final float rate = mEstimator.getRate(nextEventTime);
+        assertLessThan("Rate", rate, 1000f);
+    }
+
+    private void assertLessThan(String label, float a, float b)  {
+        assertTrue(String.format("%s was %f, but should be less than %f", label, a, b), a < b);
+    }
+
+    private void assertGreaterThan(String label, float a, float b)  {
+        assertTrue(String.format("%s was %f, but should be more than %f", label, a, b), a > b);
+    }
+
+    /** @returns the next event time. */
+    private long postEvents(long start, long dt, int num) {
+        long time = start;
+        for (int i = 0; i < num; i++) {
+            mEstimator.update(time);
+            time += dt;
+        }
+        return time;
+    }
+}