Merge "Make the dropbox rate limiter behave stricter." into udc-dev

services/core/java/com/android/server/am/DropboxRateLimiter.java

@@ -31,11 +31,17 @@ public class DropboxRateLimiter {
     // process/eventType) further entries will be rejected until RATE_LIMIT_BUFFER_DURATION has
     // elapsed, after which the current count for this breakdown will be reset.
     private static final long RATE_LIMIT_BUFFER_DURATION = 10 * DateUtils.MINUTE_IN_MILLIS;
-    // The time duration after which the rate limit buffer will be cleared.
+    // Indicated how many buffer durations to wait before the rate limit buffer will be cleared.
-    private static final long RATE_LIMIT_BUFFER_EXPIRY = 3 * RATE_LIMIT_BUFFER_DURATION;
+    // E.g. if set to 3 will wait 3xRATE_LIMIT_BUFFER_DURATION before clearing the buffer.
+    private static final long RATE_LIMIT_BUFFER_EXPIRY_FACTOR = 3;
     // The number of entries to keep per breakdown of process/eventType.
     private static final int RATE_LIMIT_ALLOWED_ENTRIES = 6;
 
+    // If a process is rate limited twice in a row we consider it crash-looping and rate limit it
+    // more aggressively.
+    private static final int STRICT_RATE_LIMIT_ALLOWED_ENTRIES = 1;
+    private static final long STRICT_RATE_LIMIT_BUFFER_DURATION = 60 * DateUtils.MINUTE_IN_MILLIS;
+
     @GuardedBy("mErrorClusterRecords")
     private final ArrayMap<String, ErrorRecord> mErrorClusterRecords = new ArrayMap<>();
     private final Clock mClock;
@@ -71,15 +77,27 @@ public class DropboxRateLimiter {
                 return new RateLimitResult(false, 0);
             }
 
-            if (now - errRecord.getStartTime() > RATE_LIMIT_BUFFER_DURATION) {
+            final long timeSinceFirstError = now - errRecord.getStartTime();
+            if (timeSinceFirstError > errRecord.getBufferDuration()) {
                 final int errCount = recentlyDroppedCount(errRecord);
                 errRecord.setStartTime(now);
                 errRecord.setCount(1);
+
+                // If this error happened exactly the next "rate limiting cycle" after the last
+                // error and the previous cycle was rate limiting then increment the successive
+                // rate limiting cycle counter. If a full "cycle" has passed since the last error
+                // then this is no longer a continuous occurrence and will be rate limited normally.
+                if (errCount > 0 && timeSinceFirstError < 2 * errRecord.getBufferDuration()) {
+                    errRecord.incrementSuccessiveRateLimitCycles();
+                } else {
+                    errRecord.setSuccessiveRateLimitCycles(0);
+                }
+
                 return new RateLimitResult(false, errCount);
             }
 
             errRecord.incrementCount();
-            if (errRecord.getCount() > RATE_LIMIT_ALLOWED_ENTRIES) {
+            if (errRecord.getCount() > errRecord.getAllowedEntries()) {
                 return new RateLimitResult(true, recentlyDroppedCount(errRecord));
             }
         }
@@ -91,16 +109,19 @@ public class DropboxRateLimiter {
      * dropped. Resets every RATE_LIMIT_BUFFER_DURATION if events are still actively created or
      * RATE_LIMIT_BUFFER_EXPIRY if not. */
     private int recentlyDroppedCount(ErrorRecord errRecord) {
-        if (errRecord == null || errRecord.getCount() < RATE_LIMIT_ALLOWED_ENTRIES) return 0;
+        if (errRecord == null || errRecord.getCount() < errRecord.getAllowedEntries()) return 0;
-        return errRecord.getCount() - RATE_LIMIT_ALLOWED_ENTRIES;
+        return errRecord.getCount() - errRecord.getAllowedEntries();
     }
 
 
-    private void maybeRemoveExpiredRecords(long now) {
+    private void maybeRemoveExpiredRecords(long currentTime) {
-        if (now - mLastMapCleanUp <= RATE_LIMIT_BUFFER_EXPIRY) return;
+        if (currentTime - mLastMapCleanUp
+                <= RATE_LIMIT_BUFFER_EXPIRY_FACTOR * RATE_LIMIT_BUFFER_DURATION) {
+            return;
+        }
 
         for (int i = mErrorClusterRecords.size() - 1; i >= 0; i--) {
-            if (now - mErrorClusterRecords.valueAt(i).getStartTime() > RATE_LIMIT_BUFFER_EXPIRY) {
+            if (mErrorClusterRecords.valueAt(i).hasExpired(currentTime)) {
                 Counter.logIncrement(
                         "stability_errors.value_dropbox_buffer_expired_count",
                         mErrorClusterRecords.valueAt(i).getCount());
@@ -108,7 +129,7 @@ public class DropboxRateLimiter {
             }
         }
 
-        mLastMapCleanUp = now;
+        mLastMapCleanUp = currentTime;
     }
 
     /** Resets the rate limiter memory. */
@@ -153,10 +174,12 @@ public class DropboxRateLimiter {
     private class ErrorRecord {
         long mStartTime;
         int mCount;
+        int mSuccessiveRateLimitCycles;
 
         ErrorRecord(long startTime, int count) {
             mStartTime = startTime;
             mCount = count;
+            mSuccessiveRateLimitCycles = 0;
         }
 
         public void setStartTime(long startTime) {
@@ -171,6 +194,14 @@ public class DropboxRateLimiter {
             mCount++;
         }
 
+        public void setSuccessiveRateLimitCycles(int successiveRateLimitCycles) {
+            mSuccessiveRateLimitCycles = successiveRateLimitCycles;
+        }
+
+        public void incrementSuccessiveRateLimitCycles() {
+            mSuccessiveRateLimitCycles++;
+        }
+
         public long getStartTime() {
             return mStartTime;
         }
@@ -178,6 +209,27 @@ public class DropboxRateLimiter {
         public int getCount() {
             return mCount;
         }
+
+        public int getSuccessiveRateLimitCycles() {
+            return mSuccessiveRateLimitCycles;
+        }
+
+        public boolean isRepeated() {
+            return mSuccessiveRateLimitCycles >= 2;
+        }
+
+        public int getAllowedEntries() {
+            return isRepeated() ? STRICT_RATE_LIMIT_ALLOWED_ENTRIES : RATE_LIMIT_ALLOWED_ENTRIES;
+        }
+
+        public long getBufferDuration() {
+            return isRepeated() ? STRICT_RATE_LIMIT_BUFFER_DURATION : RATE_LIMIT_BUFFER_DURATION;
+        }
+
+        public boolean hasExpired(long currentTime) {
+            long bufferExpiry = RATE_LIMIT_BUFFER_EXPIRY_FACTOR * getBufferDuration();
+            return currentTime - mStartTime > bufferExpiry;
+        }
     }
 
     private static class DefaultClock implements Clock {

services/tests/servicestests/src/com/android/server/am/DropboxRateLimiterTest.java

@@ -106,6 +106,64 @@ public class DropboxRateLimiterTest {
                 mRateLimiter.shouldRateLimit("tag", "p").droppedCountSinceRateLimitActivated());
     }
 
+    @Test
+    public void testStrictRepeatedLimiting() throws Exception {
+        // The first 6 entries should not be rate limited.
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        // The 7th entry of the same process should be rate limited.
+        assertTrue(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+
+        // After 11 minutes there should be nothing left in the buffer and the same type of entry
+        // should not get rate limited anymore.
+        mClock.setOffsetMillis(11 * 60 * 1000);
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        // The first 6 entries should not be rate limited again.
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+
+        // The 7th entry of the same process should be rate limited.
+        assertTrue(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+
+        // After 11 more minutes there should be nothing left in the buffer and the same type of
+        // entry should not get rate limited anymore.
+        mClock.setOffsetMillis(22 * 60 * 1000);
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+
+        // Repeated crashes after the last reset being rate limited should be restricted faster.
+        assertTrue(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+
+        // We now need to wait 61 minutes for the buffer should be empty again.
+        mClock.setOffsetMillis(83 * 60 * 1000);
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+
+        // After yet another 61 minutes, this time without triggering rate limiting, the strict
+        // limiting should be turnd off.
+        mClock.setOffsetMillis(144 * 60 * 1000);
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+
+        // As rate limiting was not triggered in the last reset, after another 11 minutes the
+        // buffer should still act as normal.
+        mClock.setOffsetMillis(155 * 60 * 1000);
+        // The first 6 entries should not be rate limited.
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        assertFalse(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+        // The 7th entry of the same process should be rate limited.
+        assertTrue(mRateLimiter.shouldRateLimit("tag", "process").shouldRateLimit());
+    }
+
     private static class TestClock implements DropboxRateLimiter.Clock {
         long mOffsetMillis = 0L;