IpConn metrics: add times to DHCP bound state

This patch adds DhcpClientEvent logging for:
 - time from init state to bound state
 - time from bound state to bound state when renewing

Example:
ConnectivityMetricsEvent(12:04:33.353, 0, 0): DhcpClientEvent(wlan0, WaitBeforeStartState, 94ms)
ConnectivityMetricsEvent(12:04:35.772, 0, 0): DhcpClientEvent(wlan0, DhcpInitState, 2417ms)
ConnectivityMetricsEvent(12:04:35.787, 0, 0): DhcpClientEvent(wlan0, DhcpRequestingState, 15ms)
ConnectivityMetricsEvent(12:04:35.793, 0, 0): DhcpClientEvent(wlan0, ConfiguringInterfaceState, 6ms)
ConnectivityMetricsEvent(12:04:35.811, 0, 0): DhcpClientEvent(wlan0, InitialBoundState, 2457ms)
ConnectivityMetricsEvent(12:05:35.791, 0, 0): DhcpClientEvent(wlan0, DhcpBoundState, 59998ms)
ConnectivityMetricsEvent(12:05:35.988, 0, 0): DhcpClientEvent(wlan0, WaitBeforeRenewalState, 196ms)
ConnectivityMetricsEvent(12:05:36.003, 0, 0): DhcpClientEvent(wlan0, DhcpRenewingState, 15ms)
ConnectivityMetricsEvent(12:05:36.010, 0, 0): DhcpClientEvent(wlan0, RenewingBoundState, 219ms)

Change-Id: I2540dd102a6509dff55936e38015265659b20760

2 files changed, 34 insertions, 3 deletions

diff --git a/core/java/android/net/metrics/DhcpClientEvent.java b/core/java/android/net/metrics/DhcpClientEvent.java
index 169f571d8317..4a9ff0511246 100644
--- a/core/java/android/net/metrics/DhcpClientEvent.java
+++ b/core/java/android/net/metrics/DhcpClientEvent.java
@@ -21,11 +21,18 @@ import android.os.Parcel;
 import android.os.Parcelable;
 
 /**
- *  An event recorded when a DhcpClient state machine transitions to a new state.
+ * An event recorded when a DhcpClient state machine transitions to a new state.
  * {@hide}
  */
 @SystemApi
 public final class DhcpClientEvent implements Parcelable {
+
+    // Names for recording DhcpClient pseudo-state transitions.
+    /** {@hide} Represents transitions from DhcpInitState to DhcpBoundState */
+    public static final String INITIAL_BOUND = "InitialBoundState";
+    /** {@hide} Represents transitions from and to DhcpBoundState via DhcpRenewingState */
+    public static final String RENEWING_BOUND = "RenewingBoundState";
+
     public final String ifName;
     public final String msg;
     public final int durationMs;
diff --git a/services/net/java/android/net/dhcp/DhcpClient.java b/services/net/java/android/net/dhcp/DhcpClient.java
index 83cfc010b4e2..ffbea9fce279 100644
--- a/services/net/java/android/net/dhcp/DhcpClient.java
+++ b/services/net/java/android/net/dhcp/DhcpClient.java
@@ -194,6 +194,10 @@ public class DhcpClient extends StateMachine {
     private long mDhcpLeaseExpiry;
     private DhcpResults mOffer;
 
+    // Milliseconds SystemClock timestamps used to record transition times to DhcpBoundState.
+    private long mLastInitEnterTime;
+    private long mLastBoundExitTime;
+
     // States.
     private State mStoppedState = new StoppedState();
     private State mDhcpState = new DhcpState();
@@ -498,13 +502,12 @@ public class DhcpClient extends StateMachine {
         public void enter() {
             if (STATE_DBG) Log.d(TAG, "Entering state " + getName());
             mEnterTimeMs = SystemClock.elapsedRealtime();
-            // TODO: record time for Init -> Bound and Bound -> Renewing -> Bound
         }
 
         @Override
         public void exit() {
             long durationMs = SystemClock.elapsedRealtime() - mEnterTimeMs;
-            mMetricsLog.log(new DhcpClientEvent(mIfaceName, getName(), (int) durationMs));
+            logState(getName(), (int) durationMs);
         }
 
         private String messageName(int what) {
@@ -742,6 +745,7 @@ public class DhcpClient extends StateMachine {
         public void enter() {
             super.enter();
             startNewTransaction();
+            mLastInitEnterTime = SystemClock.elapsedRealtime();
         }
 
         protected boolean sendPacket() {
@@ -866,6 +870,13 @@ public class DhcpClient extends StateMachine {
             }
 
             scheduleLeaseTimers();
+            logTimeToBoundState();
+        }
+
+        @Override
+        public void exit() {
+            super.exit();
+            mLastBoundExitTime = SystemClock.elapsedRealtime();
         }
 
         @Override
@@ -883,6 +894,15 @@ public class DhcpClient extends StateMachine {
                     return NOT_HANDLED;
             }
         }
+
+        private void logTimeToBoundState() {
+            long now = SystemClock.elapsedRealtime();
+            if (mLastBoundExitTime > mLastInitEnterTime) {
+                logState(DhcpClientEvent.RENEWING_BOUND, (int)(now - mLastBoundExitTime));
+            } else {
+                logState(DhcpClientEvent.INITIAL_BOUND, (int)(now - mLastInitEnterTime));
+            }
+        }
     }
 
     abstract class DhcpReacquiringState extends PacketRetransmittingState {
@@ -993,4 +1013,8 @@ public class DhcpClient extends StateMachine {
     private void logError(int errorCode) {
         mMetricsLog.log(new DhcpErrorEvent(mIfaceName, errorCode));
     }
+
+    private void logState(String name, int durationMs) {
+        mMetricsLog.log(new DhcpClientEvent(mIfaceName, name, durationMs));
+    }
 }