Add LatencyReport for every call

[This is a manual cherry pick from ub-contactsdialer-b-dev.]

This CL tracks latency for all incoming and outgoing calls. We now
measure the following latency values:
 - time for a connection service to add a call to telecom.
 - time for telecom to process a call
 - time for the dialer app to launch and have a call added to it by telecom.
 - time for dialer to check if a call should be blocked.
 - time to show a notification about the call (incoming only)
 - time it took to show the InCallUI (only if HUN wasn't displayed)

Change-Id: I08685d312cbaefc564feb4119350da71df9b9e6c

9 files changed, 267 insertions, 23 deletions

diff --git a/InCallUI/src/com/android/incallui/Call.java b/InCallUI/src/com/android/incallui/Call.java
index 252c7016d..1ad37e01a 100644
--- a/InCallUI/src/com/android/incallui/Call.java
+++ b/InCallUI/src/com/android/incallui/Call.java
@@ -375,7 +375,8 @@ public class Call {
             }
     };
 
-    private android.telecom.Call mTelecomCall;
+    private final android.telecom.Call mTelecomCall;
+    private final LatencyReport mLatencyReport;
     private boolean mIsEmergencyCall;
     private Uri mHandle;
     private final String mId;
@@ -408,7 +409,7 @@ public class Call {
 
     private long mTimeAddedMs;
 
-    private LogState mLogState = new LogState();
+    private final LogState mLogState = new LogState();
 
     /**
      * Used only to create mock calls for testing
@@ -416,6 +417,7 @@ public class Call {
     @NeededForTesting
     Call(int state) {
         mTelecomCall = null;
+        mLatencyReport = new LatencyReport();
         mId = ID_PREFIX + Integer.toString(sIdCounter++);
         setState(state);
     }
@@ -424,8 +426,8 @@ public class Call {
      * Creates a new instance of a {@link Call}.  Registers a callback for
      * {@link android.telecom.Call} events.
      */
-    public Call(android.telecom.Call telecomCall) {
-        this(telecomCall, true /* registerCallback */);
+    public Call(android.telecom.Call telecomCall, LatencyReport latencyReport) {
+        this(telecomCall, latencyReport, true /* registerCallback */);
     }
 
     /**
@@ -435,8 +437,10 @@ public class Call {
      * Intended for use when creating a {@link Call} instance for use with the
      * {@link ContactInfoCache}, where we do not want to register callbacks for the new call.
      */
-    public Call(android.telecom.Call telecomCall, boolean registerCallback) {
+    public Call(android.telecom.Call telecomCall, LatencyReport latencyReport,
+            boolean registerCallback) {
         mTelecomCall = telecomCall;
+        mLatencyReport = latencyReport;
         mId = ID_PREFIX + Integer.toString(sIdCounter++);
 
         updateFromTelecomCall(registerCallback);
@@ -1012,4 +1016,8 @@ public class Call {
     public boolean isSpam() {
         return mIsSpam;
     }
+
+    public LatencyReport getLatencyReport() {
+        return mLatencyReport;
+    }
 }
diff --git a/InCallUI/src/com/android/incallui/CallList.java b/InCallUI/src/com/android/incallui/CallList.java
index 61e8aa452..48870f68a 100644
--- a/InCallUI/src/com/android/incallui/CallList.java
+++ b/InCallUI/src/com/android/incallui/CallList.java
@@ -86,9 +86,9 @@ public class CallList {
     CallList() {
     }
 
-    public void onCallAdded(final android.telecom.Call telecomCall) {
+    public void onCallAdded(final android.telecom.Call telecomCall, LatencyReport latencyReport) {
         Trace.beginSection("onCallAdded");
-        final Call call = new Call(telecomCall);
+        final Call call = new Call(telecomCall, latencyReport);
         Log.d(this, "onCallAdded: callState=" + call.getState());
 
         if (call.getState() == Call.State.INCOMING ||
@@ -630,6 +630,12 @@ public class CallList {
         mExtendedCallInfoService = service;
     }
 
+    public void onInCallUiShown(boolean forFullScreenIntent) {
+        for (Call call : mCallById.values()) {
+            call.getLatencyReport().onInCallUiShown(forFullScreenIntent);
+        }
+    }
+
     /**
      * Listener interface for any class that wants to be notified of changes
      * to the call list.
diff --git a/InCallUI/src/com/android/incallui/ExternalCallNotifier.java b/InCallUI/src/com/android/incallui/ExternalCallNotifier.java
index 40a2e02bf..639a46da0 100644
--- a/InCallUI/src/com/android/incallui/ExternalCallNotifier.java
+++ b/InCallUI/src/com/android/incallui/ExternalCallNotifier.java
@@ -182,7 +182,7 @@ public class ExternalCallNotifier implements ExternalCallList.ExternalCallListen
         // it has available, and may make a subsequent call later (same thread) if it had to
         // call into the contacts provider for more data.
         com.android.incallui.Call incallCall = new com.android.incallui.Call(info.getCall(),
-                false /* registerCallback */);
+                new LatencyReport(), false /* registerCallback */);
 
         mContactInfoCache.findInfo(incallCall, false /* isIncoming */,
                 new ContactInfoCache.ContactInfoCacheCallback() {
diff --git a/InCallUI/src/com/android/incallui/InCallActivity.java b/InCallUI/src/com/android/incallui/InCallActivity.java
index eca79f8a7..5ae231ae1 100644
--- a/InCallUI/src/com/android/incallui/InCallActivity.java
+++ b/InCallUI/src/com/android/incallui/InCallActivity.java
@@ -77,6 +77,7 @@ public class InCallActivity extends TransactionSafeActivity implements FragmentD
     public static final String SHOW_DIALPAD_EXTRA = "InCallActivity.show_dialpad";
     public static final String DIALPAD_TEXT_EXTRA = "InCallActivity.dialpad_text";
     public static final String NEW_OUTGOING_CALL_EXTRA = "InCallActivity.new_outgoing_call";
+    public static final String FOR_FULL_SCREEN_INTENT = "InCallActivity.for_full_screen_intent";
 
     private static final String TAG_DIALPAD_FRAGMENT = "tag_dialpad_fragment";
     private static final String TAG_CONFERENCE_FRAGMENT = "tag_conference_manager_fragment";
@@ -301,6 +302,9 @@ public class InCallActivity extends TransactionSafeActivity implements FragmentD
         if (mShowPostCharWaitDialogOnResume) {
             showPostCharWaitDialog(mShowPostCharWaitDialogCallId, mShowPostCharWaitDialogChars);
         }
+
+        CallList.getInstance().onInCallUiShown(
+                getIntent().getBooleanExtra(FOR_FULL_SCREEN_INTENT, false));
     }
 
     // onPause is guaranteed to be called when the InCallActivity goes
diff --git a/InCallUI/src/com/android/incallui/InCallPresenter.java b/InCallUI/src/com/android/incallui/InCallPresenter.java
index 4442cbcd2..fac539311 100644
--- a/InCallUI/src/com/android/incallui/InCallPresenter.java
+++ b/InCallUI/src/com/android/incallui/InCallPresenter.java
@@ -27,6 +27,7 @@ import android.database.ContentObserver;
 import android.graphics.Point;
 import android.os.Bundle;
 import android.os.Handler;
+import android.os.SystemClock;
 import android.provider.CallLog;
 import android.telecom.DisconnectCause;
 import android.telecom.PhoneAccount;
@@ -513,14 +514,16 @@ public class InCallPresenter implements CallList.Listener,
     }
 
     public void onCallAdded(final android.telecom.Call call) {
+        LatencyReport latencyReport = new LatencyReport(call);
         if (shouldAttemptBlocking(call)) {
-            maybeBlockCall(call);
+            maybeBlockCall(call, latencyReport);
         } else {
+            latencyReport.onCallBlockingDone();
             if (call.getDetails()
                     .hasProperty(CallSdkCompat.Details.PROPERTY_IS_EXTERNAL_CALL)) {
                 mExternalCallList.onCallAdded(call);
             } else {
-                mCallList.onCallAdded(call);
+                mCallList.onCallAdded(call, latencyReport);
             }
         }
 
@@ -551,7 +554,8 @@ public class InCallPresenter implements CallList.Listener,
      * checking whether a function is blocked does not return in a reasonable time, we proceed
      * with adding the call anyways.
      */
-    private void maybeBlockCall(final android.telecom.Call call) {
+    private void maybeBlockCall(final android.telecom.Call call,
+            final LatencyReport latencyReport) {
         final String countryIso = GeoUtil.getCurrentCountryIso(mContext);
         final String number = TelecomCallUtil.getNumber(call);
         final long timeAdded = System.currentTimeMillis();
@@ -567,7 +571,8 @@ public class InCallPresenter implements CallList.Listener,
         final Runnable runnable = new Runnable() {
             public void run() {
                 hasTimedOut.set(true);
-                mCallList.onCallAdded(call);
+                latencyReport.onCallBlockingDone();
+                mCallList.onCallAdded(call, latencyReport);
             }
         };
         handler.postDelayed(runnable, BLOCK_QUERY_TIMEOUT_MS);
@@ -580,7 +585,8 @@ public class InCallPresenter implements CallList.Listener,
                 }
                 if (id == null) {
                     if (!hasTimedOut.get()) {
-                        mCallList.onCallAdded(call);
+                        latencyReport.onCallBlockingDone();
+                        mCallList.onCallAdded(call, latencyReport);
                     }
                 } else {
                     Log.i(this, "Rejecting incoming call from blocked number");
@@ -604,7 +610,9 @@ public class InCallPresenter implements CallList.Listener,
             Log.d(this, "checkForBlockedCall: invalid number, skipping block checking");
             if (!hasTimedOut.get()) {
                 handler.removeCallbacks(runnable);
-                mCallList.onCallAdded(call);
+
+                latencyReport.onCallBlockingDone();
+                mCallList.onCallAdded(call, latencyReport);
             }
         }
     }
diff --git a/InCallUI/src/com/android/incallui/LatencyReport.java b/InCallUI/src/com/android/incallui/LatencyReport.java
new file mode 100644
index 000000000..655372a8f
--- /dev/null
+++ b/InCallUI/src/com/android/incallui/LatencyReport.java
@@ -0,0 +1,145 @@
+/*
+ * 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.incallui;
+
+import android.os.Bundle;
+import android.os.SystemClock;
+
+import com.android.incalluibind.ObjectFactory;
+
+/**
+ * Tracks latency information for a call.
+ */
+public class LatencyReport {
+    // The following are hidden constants from android.telecom.TelecomManager.
+    private static final String EXTRA_CALL_CREATED_TIME_MILLIS =
+            "android.telecom.extra.CALL_CREATED_TIME_MILLIS";
+    private static final String EXTRA_CALL_TELECOM_ROUTING_START_TIME_MILLIS =
+            "android.telecom.extra.CALL_TELECOM_ROUTING_START_TIME_MILLIS";
+    private static final String EXTRA_CALL_TELECOM_ROUTING_END_TIME_MILLIS =
+            "android.telecom.extra.CALL_TELECOM_ROUTING_END_TIME_MILLIS";
+
+    public static final long INVALID_TIME = -1;
+
+    private final boolean mWasIncoming;
+
+    // Time elapsed since boot when the call was created by the connection service.
+    private final long mCreatedTimeMillis;
+
+    // Time elapsed since boot when telecom began processing the call.
+    private final long mTelecomRoutingStartTimeMillis;
+
+    // Time elapsed since boot when telecom finished processing the call. This includes things like
+    // looking up contact info and call blocking but before showing any UI.
+    private final long mTelecomRoutingEndTimeMillis;
+
+    // Time elapsed since boot when the call was added to the InCallUi.
+    private final long mCallAddedTimeMillis;
+
+    // Time elapsed since boot when the call was added and call blocking evaluation was completed.
+    private long mCallBlockingTimeMillis = INVALID_TIME;
+
+    // Time elapsed since boot when the call notification was shown.
+    private long mCallNotificationTimeMillis = INVALID_TIME;
+
+    // Time elapsed since boot when the InCallUI was shown.
+    private long mInCallUiShownTimeMillis = INVALID_TIME;
+
+    // Whether the call was shown to the user as a heads up notification instead of a full screen
+    // UI.
+    private boolean mDidDisplayHeadsUpNotification;
+
+    public LatencyReport() {
+        mWasIncoming = false;
+        mCreatedTimeMillis = INVALID_TIME;
+        mTelecomRoutingStartTimeMillis = INVALID_TIME;
+        mTelecomRoutingEndTimeMillis =  INVALID_TIME;
+        mCallAddedTimeMillis = SystemClock.elapsedRealtime();
+    }
+
+    public LatencyReport(android.telecom.Call telecomCall) {
+        mWasIncoming = telecomCall.getState() == android.telecom.Call.STATE_RINGING;
+        Bundle extras = telecomCall.getDetails().getIntentExtras();
+        if (extras == null) {
+            mCreatedTimeMillis = INVALID_TIME;
+            mTelecomRoutingStartTimeMillis = INVALID_TIME;
+            mTelecomRoutingEndTimeMillis =  INVALID_TIME;
+        } else {
+            mCreatedTimeMillis = extras.getLong(EXTRA_CALL_CREATED_TIME_MILLIS, INVALID_TIME);
+            mTelecomRoutingStartTimeMillis = extras.getLong(
+                    EXTRA_CALL_TELECOM_ROUTING_START_TIME_MILLIS, INVALID_TIME);
+            mTelecomRoutingEndTimeMillis = extras.getLong(
+                    EXTRA_CALL_TELECOM_ROUTING_END_TIME_MILLIS, INVALID_TIME);
+        }
+        mCallAddedTimeMillis = SystemClock.elapsedRealtime();
+    }
+
+    public boolean getWasIncoming() {
+        return mWasIncoming;
+    }
+
+    public long getCreatedTimeMillis() {
+        return mCreatedTimeMillis;
+    }
+
+    public long getTelecomRoutingStartTimeMillis() {
+        return mTelecomRoutingStartTimeMillis;
+    }
+
+    public long getTelecomRoutingEndTimeMillis() {
+        return mTelecomRoutingEndTimeMillis;
+    }
+
+    public long getCallAddedTimeMillis() {
+        return mCallAddedTimeMillis;
+    }
+
+    public long getCallBlockingTimeMillis() {
+        return mCallBlockingTimeMillis;
+    }
+
+    public void onCallBlockingDone() {
+        if (mCallBlockingTimeMillis == INVALID_TIME) {
+            mCallBlockingTimeMillis = SystemClock.elapsedRealtime();
+        }
+    }
+
+    public long getCallNotificationTimeMillis() {
+        return mCallNotificationTimeMillis;
+    }
+
+    public void onNotificationShown() {
+        if (mCallNotificationTimeMillis == INVALID_TIME) {
+            mCallNotificationTimeMillis = SystemClock.elapsedRealtime();
+        }
+    }
+
+    public long getInCallUiShownTimeMillis() {
+        return mInCallUiShownTimeMillis;
+    }
+
+    public void onInCallUiShown(boolean forFullScreenIntent) {
+        if (mInCallUiShownTimeMillis == INVALID_TIME) {
+            mInCallUiShownTimeMillis = SystemClock.elapsedRealtime();
+            mDidDisplayHeadsUpNotification = mWasIncoming && !forFullScreenIntent;
+        }
+    }
+
+    public boolean getDidDisplayHeadsUpNotification() {
+        return mDidDisplayHeadsUpNotification;
+    }
+}
diff --git a/InCallUI/src/com/android/incallui/StatusBarNotifier.java b/InCallUI/src/com/android/incallui/StatusBarNotifier.java
index 1ed3ae7dc..da553f4a3 100644
--- a/InCallUI/src/com/android/incallui/StatusBarNotifier.java
+++ b/InCallUI/src/com/android/incallui/StatusBarNotifier.java
@@ -79,6 +79,9 @@ public class StatusBarNotifier implements InCallPresenter.InCallStateListener,
     // Notification for incoming calls. This is interruptive and will show up as a HUN.
     private static final int NOTIFICATION_INCOMING_CALL = 2;
 
+    private static final int PENDING_INTENT_REQUEST_CODE_NON_FULL_SCREEN = 0;
+    private static final int PENDING_INTENT_REQUEST_CODE_FULL_SCREEN = 1;
+
     private static final long[] VIBRATE_PATTERN = new long[] {0, 1000, 1000};
 
     private final Context mContext;
@@ -290,13 +293,13 @@ public class StatusBarNotifier implements InCallPresenter.InCallStateListener,
         builder.setPublicVersion(publicBuilder.build());
 
         // Set up the main intent to send the user to the in-call screen
-        final PendingIntent inCallPendingIntent = createLaunchPendingIntent();
-        builder.setContentIntent(inCallPendingIntent);
+        builder.setContentIntent(createLaunchPendingIntent(false /* isFullScreen */));
 
         // Set the intent as a full screen intent as well if a call is incoming
         if (notificationType == NOTIFICATION_INCOMING_CALL
                 && !InCallPresenter.getInstance().isShowingInCallUi()) {
-            configureFullScreenIntent(builder, inCallPendingIntent, call);
+            configureFullScreenIntent(
+                    builder, createLaunchPendingIntent(true /* isFullScreen */), call);
             // Set the notification category for incoming calls
             builder.setCategory(Notification.CATEGORY_CALL);
         }
@@ -345,8 +348,10 @@ public class StatusBarNotifier implements InCallPresenter.InCallStateListener,
                     + mCurrentNotification);
             mNotificationManager.cancel(mCurrentNotification);
         }
+
         Log.i(this, "Displaying notification for " + notificationType);
         mNotificationManager.notify(notificationType, notification);
+        call.getLatencyReport().onNotificationShown();
         mCurrentNotification = notificationType;
     }
 
@@ -721,19 +726,24 @@ public class StatusBarNotifier implements InCallPresenter.InCallStateListener,
         return builder;
     }
 
-    private PendingIntent createLaunchPendingIntent() {
-
-        final Intent intent = InCallPresenter.getInstance().getInCallIntent(
+    private PendingIntent createLaunchPendingIntent(boolean isFullScreen) {
+        Intent intent = InCallPresenter.getInstance().getInCallIntent(
                 false /* showDialpad */, false /* newOutgoingCall */);
 
+        int requestCode = PENDING_INTENT_REQUEST_CODE_NON_FULL_SCREEN;
+        if (isFullScreen) {
+            intent.putExtra(InCallActivity.FOR_FULL_SCREEN_INTENT, true);
+            // Use a unique request code so that the pending intent isn't clobbered by the
+            // non-full screen pending intent.
+            requestCode = PENDING_INTENT_REQUEST_CODE_FULL_SCREEN;
+        }
+
         // PendingIntent that can be used to launch the InCallActivity.  The
         // system fires off this intent if the user pulls down the windowshade
         // and clicks the notification's expanded view.  It's also used to
         // launch the InCallActivity immediately when when there's an incoming
         // call (see the "fullScreenIntent" field below).
-        PendingIntent inCallPendingIntent = PendingIntent.getActivity(mContext, 0, intent, 0);
-
-        return inCallPendingIntent;
+        return PendingIntent.getActivity(mContext, requestCode, intent, 0);
     }
 
     /**
diff --git a/InCallUI/tests/src/com/android/incallui/LatencyReportTest.java b/InCallUI/tests/src/com/android/incallui/LatencyReportTest.java
new file mode 100644
index 000000000..9d8a5131b
--- /dev/null
+++ b/InCallUI/tests/src/com/android/incallui/LatencyReportTest.java
@@ -0,0 +1,59 @@
+/*
+ * 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.incallui;
+
+import static com.android.incallui.LatencyReport.INVALID_TIME;
+
+import android.os.Bundle;
+import android.telecom.Connection;
+import android.test.AndroidTestCase;
+import android.test.suitebuilder.annotation.SmallTest;
+
+import java.util.ArrayList;
+import java.util.Arrays;
+
+public class LatencyReportTest extends AndroidTestCase {
+    public void testEmptyInit() {
+        LatencyReport report = new LatencyReport();
+        assertEquals(INVALID_TIME, report.getCreatedTimeMillis());
+        assertEquals(INVALID_TIME, report.getTelecomRoutingStartTimeMillis());
+        assertEquals(INVALID_TIME, report.getTelecomRoutingEndTimeMillis());
+        assertTrue(report.getCallAddedTimeMillis() > 0);
+    }
+
+    public void testCallBlocking() {
+        LatencyReport report = new LatencyReport();
+        assertEquals(INVALID_TIME, report.getCallBlockingTimeMillis());
+        report.onCallBlockingDone();
+        assertTrue(report.getCallBlockingTimeMillis() > 0);
+    }
+
+    public void testNotificationShown() {
+        LatencyReport report = new LatencyReport();
+        assertEquals(INVALID_TIME, report.getCallNotificationTimeMillis());
+        report.onNotificationShown();
+        assertTrue(report.getCallNotificationTimeMillis() > 0);
+    }
+
+    public void testInCallUiShown() {
+        LatencyReport report = new LatencyReport();
+        assertEquals(INVALID_TIME, report.getInCallUiShownTimeMillis());
+        report.onInCallUiShown(false);
+        assertTrue(report.getInCallUiShownTimeMillis() > 0);
+        assertFalse(report.getDidDisplayHeadsUpNotification());
+    }
+}
diff --git a/src/com/android/dialer/util/IntentUtil.java b/src/com/android/dialer/util/IntentUtil.java
index 5a4a80bb1..581e10da4 100644
--- a/src/com/android/dialer/util/IntentUtil.java
+++ b/src/com/android/dialer/util/IntentUtil.java
@@ -19,6 +19,7 @@ package com.android.dialer.util;
 import android.content.Intent;
 import android.net.Uri;
 import android.os.Bundle;
+import android.os.SystemClock;
 import android.provider.ContactsContract;
 import android.telecom.PhoneAccountHandle;
 import android.telecom.TelecomManager;
@@ -37,6 +38,8 @@ public class IntentUtil {
 
     public static final String EXTRA_CALL_INITIATION_TYPE
             = "com.android.dialer.EXTRA_CALL_INITIATION_TYPE";
+    public static final String EXTRA_CALL_CREATED_TIME_MILLIS =
+            "android.telecom.extra.CALL_CREATED_TIME_MILLIS";
 
     public static class CallIntentBuilder {
         private Uri mUri;
@@ -91,6 +94,7 @@ public class IntentUtil {
         intent.putExtra(TelecomManager.EXTRA_START_CALL_WITH_VIDEO_STATE, videoState);
 
         final Bundle b = new Bundle();
+        b.putLong(EXTRA_CALL_CREATED_TIME_MILLIS, SystemClock.elapsedRealtime());
         b.putInt(EXTRA_CALL_INITIATION_TYPE, callIntiationType);
         intent.putExtra(TelecomManager.EXTRA_OUTGOING_CALL_EXTRAS, b);