Add Systrace logging to Telecom

More granular per-listener logging is protected by a
static boolean flag which is currently turned on for
dogfooding.

Bug: 18373617

Change-Id: Id37c75f2e2475923dcd66aa7325b3d8767f29a97
diff --git a/src/com/android/server/telecom/Call.java b/src/com/android/server/telecom/Call.java
index 1c842da..67ff03a 100644
--- a/src/com/android/server/telecom/Call.java
+++ b/src/com/android/server/telecom/Call.java
@@ -22,6 +22,7 @@
 import android.net.Uri;
 import android.os.Bundle;
 import android.os.Handler;
+import android.os.Trace;
 import android.provider.ContactsContract.Contacts;
 import android.telecom.CallState;
 import android.telecom.DisconnectCause;
@@ -44,7 +45,6 @@
 import com.android.internal.telephony.CallerInfoAsyncQuery.OnQueryCompleteListener;
 import com.android.internal.telephony.SmsApplication;
 import com.android.server.telecom.ContactsAsyncHelper.OnImageLoadCompleteListener;
-
 import com.android.internal.util.Preconditions;
 
 import java.util.ArrayList;
@@ -1175,6 +1175,7 @@
      * @param token The token used with this query.
      */
     private void setCallerInfo(CallerInfo callerInfo, int token) {
+        Trace.beginSection("setCallerInfo");
         Preconditions.checkNotNull(callerInfo);
 
         if (mQueryToken == token) {
@@ -1199,6 +1200,7 @@
 
             processDirectToVoicemail();
         }
+        Trace.endSection();
     }
 
     CallerInfo getCallerInfo() {
diff --git a/src/com/android/server/telecom/CallActivity.java b/src/com/android/server/telecom/CallActivity.java
index 2e34d8f..0d57b54 100644
--- a/src/com/android/server/telecom/CallActivity.java
+++ b/src/com/android/server/telecom/CallActivity.java
@@ -22,6 +22,7 @@
 import android.content.Intent;
 import android.net.Uri;
 import android.os.Bundle;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.os.UserManager;
 import android.telecom.PhoneAccount;
@@ -124,7 +125,9 @@
         intent.putExtra(CallReceiver.KEY_IS_DEFAULT_DIALER, isDefaultDialer());
 
         if (UserHandle.myUserId() == UserHandle.USER_OWNER) {
+            Trace.beginSection("processOutgoingCallIntent");
             CallReceiver.processOutgoingCallIntent(getApplicationContext(), intent);
+            Trace.endSection();
         } else {
             sendBroadcastToReceiver(intent, false /* isIncoming */);
         }
diff --git a/src/com/android/server/telecom/CallsManager.java b/src/com/android/server/telecom/CallsManager.java
index 502d75b..5c8f24f 100644
--- a/src/com/android/server/telecom/CallsManager.java
+++ b/src/com/android/server/telecom/CallsManager.java
@@ -23,6 +23,7 @@
 import android.net.Uri;
 import android.os.Bundle;
 import android.os.Handler;
+import android.os.Trace;
 import android.provider.CallLog.Calls;
 import android.telecom.AudioState;
 import android.telecom.CallState;
@@ -38,6 +39,7 @@
 import android.telephony.TelephonyManager;
 
 import com.android.internal.util.IndentingPrintWriter;
+
 import com.google.common.collect.ImmutableCollection;
 import com.google.common.collect.ImmutableList;
 
@@ -1034,20 +1036,28 @@
      * @param call The call to add.
      */
     private void addCall(Call call) {
+        Trace.beginSection("addCall");
         Log.v(this, "addCall(%s)", call);
-
         call.addListener(this);
         mCalls.add(call);
 
         // TODO: Update mForegroundCall prior to invoking
         // onCallAdded for calls which immediately take the foreground (like the first call).
         for (CallsManagerListener listener : mListeners) {
+            if (Log.SYSTRACE_DEBUG) {
+                Trace.beginSection(listener.getClass().toString() + " addCall");
+            }
             listener.onCallAdded(call);
+            if (Log.SYSTRACE_DEBUG) {
+                Trace.endSection();
+            }
         }
         updateCallsManagerState();
+        Trace.endSection();
     }
 
     private void removeCall(Call call) {
+        Trace.beginSection("removeCall");
         Log.v(this, "removeCall(%s)", call);
 
         call.setParentCall(null);  // need to clean up parent relationship before destroying.
@@ -1063,10 +1073,17 @@
         // Only broadcast changes for calls that are being tracked.
         if (shouldNotify) {
             for (CallsManagerListener listener : mListeners) {
+                if (Log.SYSTRACE_DEBUG) {
+                    Trace.beginSection(listener.getClass().toString() + " onCallRemoved");
+                }
                 listener.onCallRemoved(call);
+                if (Log.SYSTRACE_DEBUG) {
+                    Trace.endSection();
+                }
             }
             updateCallsManagerState();
         }
+        Trace.endSection();
     }
 
     /**
@@ -1092,13 +1109,21 @@
             // unexpected transition occurs.
             call.setState(newState);
 
+            Trace.beginSection("onCallStateChanged");
             // Only broadcast state change for calls that are being tracked.
             if (mCalls.contains(call)) {
                 for (CallsManagerListener listener : mListeners) {
+                    if (Log.SYSTRACE_DEBUG) {
+                        Trace.beginSection(listener.getClass().toString() + " onCallStateChanged");
+                    }
                     listener.onCallStateChanged(call, oldState, newState);
+                    if (Log.SYSTRACE_DEBUG) {
+                        Trace.endSection();
+                    }
                 }
                 updateCallsManagerState();
             }
+            Trace.endSection();
         }
     }
 
@@ -1106,6 +1131,7 @@
      * Checks which call should be visible to the user and have audio focus.
      */
     private void updateForegroundCall() {
+        Trace.beginSection("updateForegroundCall");
         Call newForegroundCall = null;
         for (Call call : mCalls) {
             // TODO: Foreground-ness needs to be explicitly set. No call, regardless
@@ -1136,9 +1162,16 @@
             mForegroundCall = newForegroundCall;
 
             for (CallsManagerListener listener : mListeners) {
+                if (Log.SYSTRACE_DEBUG) {
+                    Trace.beginSection(listener.getClass().toString() + " updateForegroundCall");
+                }
                 listener.onForegroundCallChanged(oldForegroundCall, mForegroundCall);
+                if (Log.SYSTRACE_DEBUG) {
+                    Trace.endSection();
+                }
             }
         }
+        Trace.endSection();
     }
 
     private void updateCanAddCall() {
@@ -1146,7 +1179,13 @@
         if (newCanAddCall != mCanAddCall) {
             mCanAddCall = newCanAddCall;
             for (CallsManagerListener listener : mListeners) {
+                if (Log.SYSTRACE_DEBUG) {
+                    Trace.beginSection(listener.getClass().toString() + " updateCanAddCall");
+                }
                 listener.onCanAddCallChanged(mCanAddCall);
+                if (Log.SYSTRACE_DEBUG) {
+                    Trace.endSection();
+                }
             }
         }
     }
diff --git a/src/com/android/server/telecom/InCallController.java b/src/com/android/server/telecom/InCallController.java
index 60c51e4..9498d4c 100644
--- a/src/com/android/server/telecom/InCallController.java
+++ b/src/com/android/server/telecom/InCallController.java
@@ -28,6 +28,7 @@
 import android.net.Uri;
 import android.os.IBinder;
 import android.os.RemoteException;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.telecom.AudioState;
 import android.telecom.CallProperties;
@@ -38,6 +39,7 @@
 import android.telecom.TelecomManager;
 import android.util.ArrayMap;
 
+
 // TODO: Needed for move to system service: import com.android.internal.R;
 import com.android.internal.telecom.IInCallService;
 import com.android.internal.util.IndentingPrintWriter;
@@ -337,7 +339,7 @@
      */
     private void onConnected(ComponentName componentName, IBinder service) {
         ThreadUtil.checkOnMainThread();
-
+        Trace.beginSection("onConnected: " + componentName);
         Log.i(this, "onConnected to %s", componentName);
 
         IInCallService inCallService = IInCallService.Stub.asInterface(service);
@@ -348,6 +350,7 @@
             mInCallServices.put(componentName, inCallService);
         } catch (RemoteException e) {
             Log.e(this, e, "Failed to set the in-call adapter.");
+            Trace.endSection();
             return;
         }
 
@@ -372,6 +375,7 @@
         } else {
             unbind();
         }
+        Trace.endSection();
     }
 
     /**
diff --git a/src/com/android/server/telecom/Log.java b/src/com/android/server/telecom/Log.java
index 6e3ff6d..280a470 100644
--- a/src/com/android/server/telecom/Log.java
+++ b/src/com/android/server/telecom/Log.java
@@ -34,6 +34,7 @@
     private static final String TAG = "Telecom";
 
     public static final boolean FORCE_LOGGING = false; /* STOP SHIP if true */
+    public static final boolean SYSTRACE_DEBUG = true; /* STOP SHIP if true */
     public static final boolean DEBUG = isLoggable(android.util.Log.DEBUG);
     public static final boolean INFO = isLoggable(android.util.Log.INFO);
     public static final boolean VERBOSE = isLoggable(android.util.Log.VERBOSE);
diff --git a/src/com/android/server/telecom/NewOutgoingCallIntentBroadcaster.java b/src/com/android/server/telecom/NewOutgoingCallIntentBroadcaster.java
index 9100718..b0495ac 100644
--- a/src/com/android/server/telecom/NewOutgoingCallIntentBroadcaster.java
+++ b/src/com/android/server/telecom/NewOutgoingCallIntentBroadcaster.java
@@ -22,6 +22,7 @@
 import android.content.Intent;
 import android.content.res.Resources;
 import android.net.Uri;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.telecom.GatewayInfo;
 import android.telecom.PhoneAccount;
@@ -96,6 +97,7 @@
 
         @Override
         public void onReceive(Context context, Intent intent) {
+            Trace.beginSection("onReceiveNewOutgoingCallBroadcast");
             Log.v(this, "onReceive: %s", intent);
 
             // Once the NEW_OUTGOING_CALL broadcast is finished, the resultData is used as the
@@ -116,6 +118,7 @@
                 if (mCall != null) {
                     mCall.disconnect(true /* wasViaNewOutgoingCall */);
                 }
+                Trace.endSection();
                 return;
             }
 
@@ -139,6 +142,7 @@
                             false),
                     mIntent.getIntExtra(TelecomManager.EXTRA_START_CALL_WITH_VIDEO_STATE,
                             VideoProfile.VideoState.AUDIO_ONLY));
+            Trace.endSection();
         }
     }