Merge "Implement new metrics for WifiWake" into pi-dev

5 files changed, 207 insertions, 39 deletions

diff --git a/service/java/com/android/server/wifi/WakeupController.java b/service/java/com/android/server/wifi/WakeupController.java
index e8adbb27c..2af8ec924 100644
--- a/service/java/com/android/server/wifi/WakeupController.java
+++ b/service/java/com/android/server/wifi/WakeupController.java
@@ -170,9 +170,9 @@ public class WakeupController {
         Log.d(TAG, "start()");
         mWifiInjector.getWifiScanner().registerScanListener(mScanListener);
 
-        // If already active, we don't want to re-initialize the lock, so return early.
+        // If already active, we don't want to restart the session, so return early.
         if (mIsActive) {
-            // TODO record metric for calls to start() when already active
+            mWifiWakeMetrics.recordIgnoredStart();
             return;
         }
         setActive(true);
diff --git a/service/java/com/android/server/wifi/WakeupLock.java b/service/java/com/android/server/wifi/WakeupLock.java
index 8a7422f46..c6a8f5a34 100644
--- a/service/java/com/android/server/wifi/WakeupLock.java
+++ b/service/java/com/android/server/wifi/WakeupLock.java
@@ -86,11 +86,10 @@ public class WakeupLock {
      * Maybe sets the WakeupLock as initialized based on total scans handled.
      *
      * @param numScans total number of elapsed scans in the current WifiWake session
-     * @return Whether the lock transitioned into its initialized state.
      */
-    private boolean maybeSetInitializedByScans(int numScans) {
+    private void maybeSetInitializedByScans(int numScans) {
         if (mIsInitialized) {
-            return false;
+            return;
         }
         boolean shouldBeInitialized = numScans >= CONSECUTIVE_MISSED_SCANS_REQUIRED_TO_EVICT;
         if (shouldBeInitialized) {
@@ -100,19 +99,20 @@ public class WakeupLock {
             if (mVerboseLoggingEnabled) {
                 Log.d(TAG, "State of lock: " + mLockedNetworks);
             }
+
+            // log initialize event
+            mWifiWakeMetrics.recordInitializeEvent(mNumScans, mLockedNetworks.size());
         }
-        return mIsInitialized;
     }
 
     /**
      * Maybe sets the WakeupLock as initialized based on elapsed time.
      *
      * @param timestampMillis current timestamp
-     * @return Whether the lock transitioned into its initialized state.
      */
-    private boolean maybeSetInitializedByTimeout(long timestampMillis) {
+    private void maybeSetInitializedByTimeout(long timestampMillis) {
         if (mIsInitialized) {
-            return false;
+            return;
         }
         long elapsedTime = timestampMillis - mLockTimestamp;
         boolean shouldBeInitialized = elapsedTime > MAX_LOCK_TIME_MILLIS;
@@ -121,11 +121,16 @@ public class WakeupLock {
             mIsInitialized = true;
 
             Log.d(TAG, "Lock initialized by timeout. Elapsed time: " + elapsedTime);
+            if (mNumScans == 0) {
+                Log.w(TAG, "Lock initialized with 0 handled scans!");
+            }
             if (mVerboseLoggingEnabled) {
                 Log.d(TAG, "State of lock: " + mLockedNetworks);
             }
+
+            // log initialize event
+            mWifiWakeMetrics.recordInitializeEvent(mNumScans, mLockedNetworks.size());
         }
-        return mIsInitialized;
     }
 
     /** Returns whether the lock has been fully initialized. */
@@ -159,9 +164,7 @@ public class WakeupLock {
         }
 
         // Set initialized if the lock has handled enough scans, and log the event
-        if (maybeSetInitializedByScans(mNumScans)) {
-            // TODO(easchwar) log metric
-        }
+        maybeSetInitializedByScans(mNumScans);
     }
 
     /**
@@ -220,7 +223,7 @@ public class WakeupLock {
      *
      * <p>The lock is initialized after {@link #CONSECUTIVE_MISSED_SCANS_REQUIRED_TO_EVICT}
      * scans have been handled, or after {@link #MAX_LOCK_TIME_MILLIS} milliseconds have elapsed
-     * since {@link #setLock(Collection, long)}.
+     * since {@link #setLock(Collection)}.
      *
      * @param networkList list of present ScanResultMatchInfos to update the lock with
      */
@@ -229,14 +232,12 @@ public class WakeupLock {
         if (isUnlocked()) {
             return;
         }
-        mNumScans++;
-
-        // Before checking mIsInitialized, we check to see whether we've exceeded the maximum time
-        // allowed for initialization. If so, we set initialized and treat this scan as a
+        // Before checking handling the scan, we check to see whether we've exceeded the maximum
+        // time allowed for initialization. If so, we set initialized and treat this scan as a
         // "removeFromLock()" instead of an "addToLock()".
-        if (maybeSetInitializedByTimeout(mClock.getElapsedSinceBootMillis())) {
-            // TODO(easchwar) log metric
-        }
+        maybeSetInitializedByTimeout(mClock.getElapsedSinceBootMillis());
+
+        mNumScans++;
 
         // add or remove networks based on initialized status
         if (mIsInitialized) {
diff --git a/service/java/com/android/server/wifi/WifiWakeMetrics.java b/service/java/com/android/server/wifi/WifiWakeMetrics.java
index fba72369f..5b700062d 100644
--- a/service/java/com/android/server/wifi/WifiWakeMetrics.java
+++ b/service/java/com/android/server/wifi/WifiWakeMetrics.java
@@ -42,6 +42,8 @@ public class WifiWakeMetrics {
 
     private boolean mIsInSession = false;
     private int mTotalSessions = 0;
+    private int mTotalWakeups = 0;
+    private int mIgnoredStarts = 0;
 
     private final Object mLock = new Object();
 
@@ -50,7 +52,7 @@ public class WifiWakeMetrics {
      *
      * <p>Starts the session.
      *
-     * @param numNetworks The total number of networks stored in the WakeupLock at initialization.
+     * @param numNetworks The total number of networks stored in the WakeupLock at start.
      */
     public void recordStartEvent(int numNetworks) {
         synchronized (mLock) {
@@ -60,10 +62,29 @@ public class WifiWakeMetrics {
     }
 
     /**
+     * Records the initialize event of the current Wifi Wake session.
+     *
+     * <p>Note: The start event must be recorded before this event, otherwise this call will be
+     * ignored.
+     *
+     * @param numScans The total number of elapsed scans since start.
+     * @param numNetworks The total number of networks in the lock.
+     */
+    public void recordInitializeEvent(int numScans, int numNetworks) {
+        synchronized (mLock) {
+            if (!mIsInSession) {
+                return;
+            }
+            mCurrentSession.recordInitializeEvent(numScans, numNetworks,
+                    SystemClock.elapsedRealtime());
+        }
+    }
+
+    /**
      * Records the unlock event of the current Wifi Wake session.
      *
      * <p>The unlock event occurs when the WakeupLock has all of its networks removed. This event
-     * will not be recorded if the start event recorded 0 locked networks.
+     * will not be recorded if the initialize event recorded 0 locked networks.
      *
      * <p>Note: The start event must be recorded before this event, otherwise this call will be
      * ignored.
@@ -116,6 +137,11 @@ public class WifiWakeMetrics {
             }
             mCurrentSession.recordResetEvent(numScans, SystemClock.elapsedRealtime());
 
+            // tally successful wakeups here since this is the actual point when wifi is turned on
+            if (mCurrentSession.hasWakeupTriggered()) {
+                mTotalWakeups++;
+            }
+
             mTotalSessions++;
             if (mSessions.size() < MAX_RECORDED_SESSIONS) {
                 mSessions.add(mCurrentSession);
@@ -125,12 +151,21 @@ public class WifiWakeMetrics {
     }
 
     /**
+     * Records instance of the start event being ignored due to the controller already being active.
+     */
+    public void recordIgnoredStart() {
+        mIgnoredStarts++;
+    }
+
+    /**
      * Returns the consolidated WifiWakeStats proto for WifiMetrics.
      */
     public WifiWakeStats buildProto() {
         WifiWakeStats proto = new WifiWakeStats();
 
         proto.numSessions = mTotalSessions;
+        proto.numWakeups = mTotalWakeups;
+        proto.numIgnoredStarts = mIgnoredStarts;
         proto.sessions = new WifiWakeStats.Session[mSessions.size()];
 
         for (int i = 0; i < mSessions.size(); i++) {
@@ -148,6 +183,8 @@ public class WifiWakeMetrics {
         synchronized (mLock) {
             pw.println("-------WifiWake metrics-------");
             pw.println("mTotalSessions: " + mTotalSessions);
+            pw.println("mTotalWakeups: " + mTotalWakeups);
+            pw.println("mIgnoredStarts: " + mIgnoredStarts);
             pw.println("mIsInSession: " + mIsInSession);
             pw.println("Stored Sessions: " + mSessions.size());
             for (Session session : mSessions) {
@@ -167,21 +204,29 @@ public class WifiWakeMetrics {
      * <p>Keeps the current WifiWake session.
      */
     public void clear() {
-        mSessions.clear();
-        mTotalSessions = 0;
+        synchronized (mLock) {
+            mSessions.clear();
+            mTotalSessions = 0;
+            mTotalWakeups = 0;
+            mIgnoredStarts = 0;
+        }
     }
 
     /** A single WifiWake session. */
     public static class Session {
 
         private final long mStartTimestamp;
-        private final int mNumNetworks;
+        private final int mStartNetworks;
+        private int mInitializeNetworks = 0;
 
         @VisibleForTesting
         @Nullable
         Event mUnlockEvent;
         @VisibleForTesting
         @Nullable
+        Event mInitEvent;
+        @VisibleForTesting
+        @Nullable
         Event mWakeupEvent;
         @VisibleForTesting
         @Nullable
@@ -189,11 +234,27 @@ public class WifiWakeMetrics {
 
         /** Creates a new WifiWake session. */
         public Session(int numNetworks, long timestamp) {
-            mNumNetworks = numNetworks;
+            mStartNetworks = numNetworks;
             mStartTimestamp = timestamp;
         }
 
         /**
+         * Records an initialize event.
+         *
+         * <p>Ignores subsequent calls.
+         *
+         * @param numScans Total number of scans at the time of this event.
+         * @param numNetworks Total number of networks in the lock.
+         * @param timestamp The timestamp of the event.
+         */
+        public void recordInitializeEvent(int numScans, int numNetworks, long timestamp) {
+            if (mInitEvent == null) {
+                mInitializeNetworks = numNetworks;
+                mInitEvent = new Event(numScans, timestamp - mStartTimestamp);
+            }
+        }
+
+        /**
          * Records an unlock event.
          *
          * <p>Ignores subsequent calls.
@@ -222,6 +283,13 @@ public class WifiWakeMetrics {
         }
 
         /**
+         * Returns whether the current session has had its wakeup event triggered.
+         */
+        public boolean hasWakeupTriggered() {
+            return mWakeupEvent != null;
+        }
+
+        /**
          * Records a reset event.
          *
          * <p>Ignores subsequent calls.
@@ -239,8 +307,12 @@ public class WifiWakeMetrics {
         public WifiWakeStats.Session buildProto() {
             WifiWakeStats.Session sessionProto = new WifiWakeStats.Session();
             sessionProto.startTimeMillis = mStartTimestamp;
-            sessionProto.lockedNetworksAtStart = mNumNetworks;
+            sessionProto.lockedNetworksAtStart = mStartNetworks;
 
+            if (mInitEvent != null) {
+                sessionProto.lockedNetworksAtInitialize = mInitializeNetworks;
+                sessionProto.initializeEvent = mInitEvent.buildProto();
+            }
             if (mUnlockEvent != null) {
                 sessionProto.unlockEvent = mUnlockEvent.buildProto();
             }
@@ -258,7 +330,9 @@ public class WifiWakeMetrics {
         public void dump(PrintWriter pw) {
             pw.println("WifiWakeMetrics.Session:");
             pw.println("mStartTimestamp: " + mStartTimestamp);
-            pw.println("mNumNetworks: " + mNumNetworks);
+            pw.println("mStartNetworks: " + mStartNetworks);
+            pw.println("mInitializeNetworks: " + mInitializeNetworks);
+            pw.println("mInitEvent: " + (mInitEvent == null ? "{}" : mInitEvent.toString()));
             pw.println("mUnlockEvent: " + (mUnlockEvent == null ? "{}" : mUnlockEvent.toString()));
             pw.println("mWakeupEvent: " + (mWakeupEvent == null ? "{}" : mWakeupEvent.toString()));
             pw.println("mResetEvent: " + (mResetEvent == null ? "{}" : mResetEvent.toString()));
diff --git a/tests/wifitests/src/com/android/server/wifi/WakeupControllerTest.java b/tests/wifitests/src/com/android/server/wifi/WakeupControllerTest.java
index 1aedae286..1af2d65e2 100644
--- a/tests/wifitests/src/com/android/server/wifi/WakeupControllerTest.java
+++ b/tests/wifitests/src/com/android/server/wifi/WakeupControllerTest.java
@@ -210,6 +210,16 @@ public class WakeupControllerTest {
     }
 
     /**
+     * Verify that start does not record an ignored start call if the controller is not yet active.
+     */
+    @Test
+    public void startDoesNotRecordIgnoredStart() {
+        initializeWakeupController(true /* enabled */);
+        mWakeupController.start();
+        verify(mWifiWakeMetrics, never()).recordIgnoredStart();
+    }
+
+    /**
      * Verify that start does not set the wakeup lock when feature is disabled.
      */
     @Test
@@ -221,10 +231,10 @@ public class WakeupControllerTest {
     }
 
     /**
-     * Verify that start does not set the wakeup lock if the controller is already active.
+     * If the controller is already active, verify that start() is ignored and no setup is done.
      */
     @Test
-    public void startDoesNotSetWakeupLockIfAlreadyActive() {
+    public void startIsIgnoredIfAlreadyActive() {
         initializeWakeupController(true /* enabled */);
         InOrder lockInOrder = Mockito.inOrder(mWakeupLock);
         InOrder metricsInOrder = Mockito.inOrder(mWifiWakeMetrics);
@@ -235,8 +245,9 @@ public class WakeupControllerTest {
 
         mWakeupController.stop();
         mWakeupController.start();
-        lockInOrder.verify(mWakeupLock, never()).setLock(any());
+        metricsInOrder.verify(mWifiWakeMetrics).recordIgnoredStart();
         metricsInOrder.verify(mWifiWakeMetrics, never()).recordStartEvent(anyInt());
+        lockInOrder.verify(mWakeupLock, never()).setLock(any());
     }
 
     /**
diff --git a/tests/wifitests/src/com/android/server/wifi/WifiWakeMetricsTest.java b/tests/wifitests/src/com/android/server/wifi/WifiWakeMetricsTest.java
index 37a658976..9d55f9dc7 100644
--- a/tests/wifitests/src/com/android/server/wifi/WifiWakeMetricsTest.java
+++ b/tests/wifitests/src/com/android/server/wifi/WifiWakeMetricsTest.java
@@ -17,8 +17,10 @@
 package com.android.server.wifi;
 
 import static junit.framework.Assert.assertEquals;
+import static junit.framework.Assert.assertFalse;
 import static junit.framework.Assert.assertNotNull;
 import static junit.framework.Assert.assertNull;
+import static junit.framework.Assert.assertTrue;
 
 import com.android.server.wifi.nano.WifiMetricsProto.WifiWakeStats;
 
@@ -40,6 +42,8 @@ public class WifiWakeMetricsTest {
         WifiWakeStats wifiWakeStats = mWifiWakeMetrics.buildProto();
         assertNotNull(wifiWakeStats);
         assertEquals(wifiWakeStats.numSessions, 0);
+        assertEquals(wifiWakeStats.numWakeups, 0);
+        assertEquals(wifiWakeStats.numIgnoredStarts, 0);
         assertEquals(wifiWakeStats.sessions.length, 0);
     }
 
@@ -57,6 +61,7 @@ public class WifiWakeMetricsTest {
         WifiWakeStats wifiWakeStats = mWifiWakeMetrics.buildProto();
         assertNotNull(wifiWakeStats);
         assertEquals(wifiWakeStats.numSessions, 3);
+        assertEquals(wifiWakeStats.numWakeups, 0);
         assertEquals(wifiWakeStats.sessions.length, 3);
     }
 
@@ -65,12 +70,16 @@ public class WifiWakeMetricsTest {
         int numSessions = WifiWakeMetrics.MAX_RECORDED_SESSIONS + 1;
         for (int i = 0; i < numSessions; i++) {
             mWifiWakeMetrics.recordStartEvent(i);
+            mWifiWakeMetrics.recordInitializeEvent(i, i);
+            mWifiWakeMetrics.recordUnlockEvent(i);
+            mWifiWakeMetrics.recordWakeupEvent(i);
             mWifiWakeMetrics.recordResetEvent(i);
         }
 
         WifiWakeStats wifiWakeStats = mWifiWakeMetrics.buildProto();
         assertNotNull(wifiWakeStats);
         assertEquals(wifiWakeStats.numSessions, numSessions);
+        assertEquals(wifiWakeStats.numWakeups, numSessions);
         assertEquals(wifiWakeStats.sessions.length, WifiWakeMetrics.MAX_RECORDED_SESSIONS);
 
         // ensure that the first (not last) MAX_RECORDED_SESSIONS are recorded
@@ -78,10 +87,57 @@ public class WifiWakeMetricsTest {
             WifiWakeStats.Session session = wifiWakeStats.sessions[i];
             assertNotNull(session);
             assertEquals(session.lockedNetworksAtStart, i);
+            assertEquals(session.lockedNetworksAtInitialize, i);
         }
     }
 
     @Test
+    public void buildProtoCountsWakes() {
+        mWifiWakeMetrics.recordStartEvent(0 /* numNetworks */);
+        mWifiWakeMetrics.recordWakeupEvent(3 /* numScans */);
+        mWifiWakeMetrics.recordResetEvent(3 /* numScans */);
+
+        mWifiWakeMetrics.recordStartEvent(1 /* numNetworks */);
+        mWifiWakeMetrics.recordWakeupEvent(3 /* numScans */);
+        mWifiWakeMetrics.recordResetEvent(3 /* numScans */);
+
+        mWifiWakeMetrics.recordStartEvent(2 /* numNetworks */);
+        mWifiWakeMetrics.recordResetEvent(0 /* numScans */);
+
+        WifiWakeStats wifiWakeStats = mWifiWakeMetrics.buildProto();
+        assertNotNull(wifiWakeStats);
+        assertEquals(wifiWakeStats.numSessions, 3);
+        assertEquals(wifiWakeStats.numWakeups, 2);
+        assertEquals(wifiWakeStats.sessions.length, 3);
+    }
+
+    @Test
+    public void buildProtoDoesNotCountWakeInCurrentSession() {
+        mWifiWakeMetrics.recordStartEvent(1 /* numNetworks */);
+        mWifiWakeMetrics.recordResetEvent(0 /* numScans */);
+
+        mWifiWakeMetrics.recordStartEvent(2 /* numNetworks */);
+        mWifiWakeMetrics.recordWakeupEvent(3 /* numScans */);
+
+        WifiWakeStats wifiWakeStats = mWifiWakeMetrics.buildProto();
+        assertNotNull(wifiWakeStats);
+        assertEquals(wifiWakeStats.numSessions, 1);
+        assertEquals(wifiWakeStats.numWakeups, 0);
+        assertEquals(wifiWakeStats.sessions.length, 1);
+    }
+
+    @Test
+    public void buildProtoCountsIgnoredStarts() {
+        mWifiWakeMetrics.recordIgnoredStart();
+        mWifiWakeMetrics.recordIgnoredStart();
+        mWifiWakeMetrics.recordIgnoredStart();
+
+        WifiWakeStats wifiWakeStats = mWifiWakeMetrics.buildProto();
+        assertNotNull(wifiWakeStats);
+        assertEquals(wifiWakeStats.numIgnoredStarts, 3);
+    }
+
+    @Test
     public void buildProtoDoesNotIncludeCurrentSession() {
         mWifiWakeMetrics.recordStartEvent(1 /* numNetworks */);
         mWifiWakeMetrics.recordResetEvent(0 /* numScans */);
@@ -130,24 +186,31 @@ public class WifiWakeMetricsTest {
     @Test
     public void clearRemovesSessions() {
         mWifiWakeMetrics.recordStartEvent(0 /* numNetworks */);
-        mWifiWakeMetrics.recordResetEvent(0 /* numScans */);
+        mWifiWakeMetrics.recordWakeupEvent(3 /* numScans */);
+        mWifiWakeMetrics.recordResetEvent(3 /* numScans */);
 
         mWifiWakeMetrics.recordStartEvent(0 /* numNetworks */);
         mWifiWakeMetrics.recordResetEvent(0 /* numScans */);
 
         mWifiWakeMetrics.recordStartEvent(0 /* numNetworks */);
+        mWifiWakeMetrics.recordIgnoredStart();
+        mWifiWakeMetrics.recordIgnoredStart();
         mWifiWakeMetrics.recordResetEvent(0 /* numScans */);
 
         // verify sessions
         WifiWakeStats wifiWakeStats = mWifiWakeMetrics.buildProto();
         assertNotNull(wifiWakeStats);
         assertEquals(wifiWakeStats.numSessions, 3);
+        assertEquals(wifiWakeStats.numWakeups, 1);
+        assertEquals(wifiWakeStats.numIgnoredStarts, 2);
         assertEquals(wifiWakeStats.sessions.length, 3);
 
         mWifiWakeMetrics.clear();
         wifiWakeStats = mWifiWakeMetrics.buildProto();
         assertNotNull(wifiWakeStats);
         assertEquals(wifiWakeStats.numSessions, 0);
+        assertEquals(wifiWakeStats.numWakeups, 0);
+        assertEquals(wifiWakeStats.numIgnoredStarts, 0);
         assertEquals(wifiWakeStats.sessions.length, 0);
     }
 
@@ -209,18 +272,21 @@ public class WifiWakeMetricsTest {
         WifiWakeMetrics.Session session =
                 new WifiWakeMetrics.Session(1 /* numNetworks */, 1000 /* timestamp */);
 
-        session.recordUnlockEvent(1 /* numScans */, 1100 /* timestamp */);
-        session.recordWakeupEvent(2 /* numScans */, 1200 /* timestamp */);
-        session.recordResetEvent(3 /* numScans */, 1300 /* timestamp */);
+        session.recordInitializeEvent(1 /* numScans */, 2 /* numNetworks */, 1100 /* timestamp */);
+        session.recordUnlockEvent(2 /* numScans */, 1200 /* timestamp */);
+        session.recordWakeupEvent(3 /* numScans */, 1300 /* timestamp */);
+        session.recordResetEvent(4 /* numScans */, 1400 /* timestamp */);
 
         WifiWakeStats.Session sessionProto = session.buildProto();
         assertNotNull(sessionProto);
         assertEquals(sessionProto.lockedNetworksAtStart, 1);
+        assertEquals(sessionProto.lockedNetworksAtInitialize, 2);
         assertEquals(sessionProto.startTimeMillis, 1000);
 
-        verifyEventProto(sessionProto.unlockEvent, 1, 100);
-        verifyEventProto(sessionProto.wakeupEvent, 2, 200);
-        verifyEventProto(sessionProto.resetEvent, 3, 300);
+        verifyEventProto(sessionProto.initializeEvent, 1, 100);
+        verifyEventProto(sessionProto.unlockEvent, 2, 200);
+        verifyEventProto(sessionProto.wakeupEvent, 3, 300);
+        verifyEventProto(sessionProto.resetEvent, 4, 400);
     }
 
     @Test
@@ -239,6 +305,22 @@ public class WifiWakeMetricsTest {
     }
 
     @Test
+    public void session_hasWakeupTriggered() {
+        WifiWakeMetrics.Session session =
+                new WifiWakeMetrics.Session(0 /* numNetworks */, 1000 /* timestamp */);
+        assertFalse(session.hasWakeupTriggered());
+
+        session.recordInitializeEvent(3 /* numScans */, 0 /* numNetworks */, 1100 /* timestamp */);
+        assertFalse(session.hasWakeupTriggered());
+
+        session.recordWakeupEvent(3 /* numScans */, 1100 /* timestamp */);
+        assertTrue(session.hasWakeupTriggered());
+
+        session.recordResetEvent(3 /* numScans */, 1100 /* timestamp */);
+        assertTrue(session.hasWakeupTriggered());
+    }
+
+    @Test
     public void event_buildsProto() {
         WifiWakeMetrics.Event event =
                 new WifiWakeMetrics.Event(1 /* numScans */, 1000 /* elapsedTime */);