Only log dropped events every two seconds

If a device enters a state where the Sensor Event Connection's cache
is full, it would generate a log for every new event it received which
led to a large number of logs. This patch rate-limits how often the
dropped event log line is output and summarizes the number of events
that were dropped.

Bug: 120790102
Test: Builds, verified log was generated at most once every two
      seconds per SensorEventConnection

Change-Id: I61d84bc15dd72d5d36d250ce40ace200d549a6c0
diff --git a/services/sensorservice/SensorEventConnection.cpp b/services/sensorservice/SensorEventConnection.cpp
index 8dc80cc..776efab 100644
--- a/services/sensorservice/SensorEventConnection.cpp
+++ b/services/sensorservice/SensorEventConnection.cpp
@@ -32,8 +32,9 @@
         const String16& opPackageName, bool hasSensorAccess)
     : mService(service), mUid(uid), mWakeLockRefCount(0), mHasLooperCallbacks(false),
       mDead(false), mDataInjectionMode(isDataInjectionMode), mEventCache(nullptr),
-      mCacheSize(0), mMaxCacheSize(0), mPackageName(packageName), mOpPackageName(opPackageName),
-      mDestroyed(false), mHasSensorAccess(hasSensorAccess) {
+      mCacheSize(0), mMaxCacheSize(0), mTimeOfLastEventDrop(0), mEventsDropped(0),
+      mPackageName(packageName), mOpPackageName(opPackageName), mDestroyed(false),
+      mHasSensorAccess(hasSensorAccess) {
     mChannel = new BitTube(mService->mSocketBufferSize);
 #if DEBUG_CONNECTIONS
     mEventsReceived = mEventsSentFromCache = mEventsSent = 0;
@@ -405,9 +406,6 @@
         reAllocateCacheLocked(events, count);
     } else {
         // The events do not fit within the cache: drop the oldest events.
-        ALOGW("Dropping events from cache (%d / %d) to save %d newer events", mCacheSize,
-                mMaxCacheSize, count);
-
         int freeSpace = mMaxCacheSize - mCacheSize;
 
         // Drop up to the currently cached number of events to make room for new events
@@ -419,6 +417,18 @@
         // Determine the number of new events to copy into the cache
         int eventsToCopy = std::min(mMaxCacheSize, count);
 
+        constexpr nsecs_t kMinimumTimeBetweenDropLogNs = 2 * 1000 * 1000 * 1000; // 2 sec
+        if (events[0].timestamp - mTimeOfLastEventDrop > kMinimumTimeBetweenDropLogNs) {
+            ALOGW("Dropping %d cached events (%d/%d) to save %d/%d new events. %d events previously"
+                    " dropped", cachedEventsToDrop, mCacheSize, mMaxCacheSize, eventsToCopy,
+                    count, mEventsDropped);
+            mEventsDropped = 0;
+            mTimeOfLastEventDrop = events[0].timestamp;
+        } else {
+            // Record the number dropped
+            mEventsDropped += cachedEventsToDrop + newEventsToDrop;
+        }
+
         // Check for any flush complete events in the events that will be dropped
         countFlushCompleteEventsLocked(mEventCache, cachedEventsToDrop);
         countFlushCompleteEventsLocked(events, newEventsToDrop);