Merge "Readability improvements in Logging"

telecomm/java/android/telecom/ConnectionService.java

@@ -515,9 +515,12 @@ public abstract class ConnectionService extends Service {
                         final boolean isUnknown = args.argi2 == 1;
                         if (!mAreAccountsInitialized) {
                             Log.d(this, "Enqueueing pre-init request %s", id);
-                            mPreInitializationConnectionRequests.add(new Runnable() {
+                            mPreInitializationConnectionRequests.add(
+                                    new android.telecom.Logging.Runnable(
+                                            SESSION_HANDLER + SESSION_CREATE_CONN + ".pICR",
+                                            null /*lock*/) {
                                 @Override
-                                public void run() {
+                                public void loggedRun() {
                                     createConnection(
                                             connectionManagerPhoneAccount,
                                             id,
@@ -525,7 +528,7 @@ public abstract class ConnectionService extends Service {
                                             isIncoming,
                                             isUnknown);
                                 }
-                            });
+                            }.prepare());
                         } else {
                             createConnection(
                                     connectionManagerPhoneAccount,
@@ -1378,9 +1381,9 @@ public abstract class ConnectionService extends Service {
             public void onResult(
                     final List<ComponentName> componentNames,
                     final List<IBinder> services) {
-                mHandler.post(new Runnable() {
+                mHandler.post(new android.telecom.Logging.Runnable("oAA.qRCS.oR", null /*lock*/) {
                     @Override
-                    public void run() {
+                    public void loggedRun() {
                         for (int i = 0; i < componentNames.size() && i < services.size(); i++) {
                             mRemoteConnectionManager.addConnectionService(
                                     componentNames.get(i),
@@ -1389,17 +1392,17 @@ public abstract class ConnectionService extends Service {
                         onAccountsInitialized();
                         Log.d(this, "remote connection services found: " + services);
                     }
-                });
+                }.prepare());
             }
 
             @Override
             public void onError() {
-                mHandler.post(new Runnable() {
+                mHandler.post(new android.telecom.Logging.Runnable("oAA.qRCS.oE", null /*lock*/) {
                     @Override
-                    public void run() {
+                    public void loggedRun() {
                         mAreAccountsInitialized = true;
                     }
-                });
+                }.prepare());
             }
         });
     }

telecomm/java/android/telecom/Log.java

@@ -48,13 +48,13 @@ public class Log {
     // Generic tag for all Telecom logging
     @VisibleForTesting
     public static String TAG = "TelecomFramework";
+    public static boolean DEBUG = isLoggable(android.util.Log.DEBUG);
+    public static boolean INFO = isLoggable(android.util.Log.INFO);
+    public static boolean VERBOSE = isLoggable(android.util.Log.VERBOSE);
+    public static boolean WARN = isLoggable(android.util.Log.WARN);
+    public static boolean ERROR = isLoggable(android.util.Log.ERROR);
 
     private static final boolean FORCE_LOGGING = false; /* 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);
-    public static final boolean WARN = isLoggable(android.util.Log.WARN);
-    public static final boolean ERROR = isLoggable(android.util.Log.ERROR);
 
     // Used to synchronize singleton logging lazy initialization
     private static final Object sSingletonSync = new Object();
@@ -340,6 +340,11 @@ public class Log {
 
     public static void setTag(String tag) {
         TAG = tag;
+        DEBUG = isLoggable(android.util.Log.DEBUG);
+        INFO = isLoggable(android.util.Log.INFO);
+        VERBOSE = isLoggable(android.util.Log.VERBOSE);
+        WARN = isLoggable(android.util.Log.WARN);
+        ERROR = isLoggable(android.util.Log.ERROR);
     }
 
     /**

telecomm/java/android/telecom/Logging/Runnable.java

@@ -27,7 +27,7 @@ public abstract class Runnable {
 
     private Session mSubsession;
     private final String mSubsessionName;
-    private final Object mLock = new Object();
+    private final Object mLock;
     private final java.lang.Runnable mRunnable = new java.lang.Runnable() {
         @Override
         public void run() {
@@ -45,7 +45,18 @@ public abstract class Runnable {
         }
     };
 
-    public Runnable(String subsessionName) {
+    /**
+     * Creates a new Telecom Runnable that incorporates Session Logging into it. Useful for carrying
+     * Logging Sessions through different threads as well as through handlers.
+     * @param subsessionName The name that will be used in the Logs to mark this Session
+     * @param lock The synchronization lock that will be used to lock loggedRun().
+     */
+    public Runnable(String subsessionName, Object lock) {
+        if (lock == null) {
+            mLock = new Object();
+        } else {
+            mLock = lock;
+        }
         mSubsessionName = subsessionName;
     }
 

telecomm/java/android/telecom/Logging/Session.java

@@ -19,6 +19,7 @@ package android.telecom.Logging;
 import android.annotation.NonNull;
 import android.os.Parcel;
 import android.os.Parcelable;
+import android.telecom.Log;
 import android.text.TextUtils;
 
 import com.android.internal.annotations.VisibleForTesting;
@@ -26,20 +27,23 @@ import com.android.internal.annotations.VisibleForTesting;
 import java.util.ArrayList;
 
 /**
- * The session that stores information about a thread's point of entry into the Telecom code that
+ * Stores information about a thread's point of entry into that should persist until that thread
- * persists until the thread exits Telecom.
+ * exits.
  * @hide
  */
 public class Session {
 
     public static final String START_SESSION = "START_SESSION";
+    public static final String START_EXTERNAL_SESSION = "START_EXTERNAL_SESSION";
     public static final String CREATE_SUBSESSION = "CREATE_SUBSESSION";
     public static final String CONTINUE_SUBSESSION = "CONTINUE_SUBSESSION";
     public static final String END_SUBSESSION = "END_SUBSESSION";
     public static final String END_SESSION = "END_SESSION";
 
     public static final String SUBSESSION_SEPARATION_CHAR = "->";
+    public static final String SESSION_SEPARATION_CHAR_CHILD = "_";
     public static final String EXTERNAL_INDICATOR = "E-";
+    public static final String TRUNCATE_STRING = "...";
 
     /**
      * Initial value of mExecutionEndTimeMs and the final value of {@link #getLocalExecutionTime()}
@@ -49,15 +53,19 @@ public class Session {
 
     public static class Info implements Parcelable {
         public final String sessionId;
-        public final String shortMethodName;
+        public final String methodPath;
 
-        private Info(String id, String methodName) {
+        private Info(String id, String path) {
             sessionId = id;
-            shortMethodName = methodName;
+            methodPath = path;
         }
 
         public static Info getInfo (Session s) {
-            return new Info(s.getFullSessionId(), s.getShortMethodName());
+            // Create Info based on the truncated method path if the session is external, so we do
+            // not get multiple stacking external sessions (unless we have DEBUG level logging or
+            // lower).
+            return new Info(s.getFullSessionId(), s.getFullMethodPath(
+                    !Log.DEBUG && s.isSessionExternal()));
         }
 
         /** Responsible for creating Info objects for deserialized Parcels. */
@@ -86,7 +94,7 @@ public class Session {
         @Override
         public void writeToParcel(Parcel destination, int flags) {
             destination.writeString(sessionId);
-            destination.writeString(shortMethodName);
+            destination.writeString(methodPath);
         }
     }
 
@@ -226,7 +234,15 @@ public class Session {
         if (parentSession == null) {
             return mSessionId;
         } else {
-            return parentSession.getFullSessionId() + "_" + mSessionId;
+            if (Log.VERBOSE) {
+                return parentSession.getFullSessionId() +
+                        // Append "_X" to subsession to show subsession designation.
+                        SESSION_SEPARATION_CHAR_CHILD + mSessionId;
+            } else {
+                // Only worry about the base ID at the top of the tree.
+                return parentSession.getFullSessionId();
+            }
+
         }
     }
 
@@ -259,16 +275,18 @@ public class Session {
     }
 
     // Recursively concatenate mShortMethodName with the parent Sessions to create full method
-    // path. Caches this string so that multiple calls for the path will be quick.
+    // path. if truncatePath is set to true, all other external sessions (except for the most
-    public String getFullMethodPath() {
+    // recent) will be truncated to "..."
+    public String getFullMethodPath(boolean truncatePath) {
         StringBuilder sb = new StringBuilder();
-        getFullMethodPath(sb);
+        getFullMethodPath(sb, truncatePath);
         return sb.toString();
     }
 
-    private synchronized void getFullMethodPath(StringBuilder sb) {
+    private synchronized void getFullMethodPath(StringBuilder sb, boolean truncatePath) {
-        // Don't calculate if we have already figured it out!
+        // Return cached value for method path. When returning the truncated path, recalculate the
-        if (!TextUtils.isEmpty(mFullMethodPathCache)) {
+        // full path without using the cached value.
+        if (!TextUtils.isEmpty(mFullMethodPathCache) && !truncatePath) {
             sb.append(mFullMethodPathCache);
             return;
         }
@@ -278,25 +296,37 @@ public class Session {
             // Check to see if the session has been renamed yet. If it has not, then the session
             // has not been continued.
             isSessionStarted = !mShortMethodName.equals(parentSession.mShortMethodName);
-            parentSession.getFullMethodPath(sb);
+            parentSession.getFullMethodPath(sb, truncatePath);
             sb.append(SUBSESSION_SEPARATION_CHAR);
         }
         // Encapsulate the external session's method name so it is obvious what part of the session
-        // is external.
+        // is external or truncate it if we do not want the entire history.
         if (isExternal()) {
+            if (truncatePath) {
+                sb.append(TRUNCATE_STRING);
+            } else {
                 sb.append("(");
                 sb.append(mShortMethodName);
                 sb.append(")");
+            }
         } else {
             sb.append(mShortMethodName);
         }
-
+        // If we are returning the truncated path, do not save that path as the full path.
-        if(isSessionStarted) {
+        if (isSessionStarted && !truncatePath) {
             // Cache this value so that we do not have to do this work next time!
             // We do not cache the value if the session being evaluated hasn't been continued yet.
             mFullMethodPathCache = sb.toString();
         }
     }
+    // Recursively move to the top of the tree to see if the parent session is external.
+    private boolean isSessionExternal() {
+        if (getParentSession() == null) {
+            return isExternal();
+        } else {
+            return getParentSession().isSessionExternal();
+        }
+    }
 
     @Override
     public int hashCode() {
@@ -350,7 +380,7 @@ public class Session {
             return mParentSession.toString();
         } else {
             StringBuilder methodName = new StringBuilder();
-            methodName.append(getFullMethodPath());
+            methodName.append(getFullMethodPath(false /*truncatePath*/));
             if (mOwnerInfo != null && !mOwnerInfo.isEmpty()) {
                 methodName.append("(InCall package: ");
                 methodName.append(mOwnerInfo);

telecomm/java/android/telecom/Logging/SessionManager.java

@@ -177,8 +177,9 @@ public class SessionManager {
         }
 
         // Create Session from Info and add to the sessionMapper under this ID.
+        Log.d(LOGGING_TAG, Session.START_EXTERNAL_SESSION);
         Session externalSession = new Session(Session.EXTERNAL_INDICATOR + sessionInfo.sessionId,
-                sessionInfo.shortMethodName, System.currentTimeMillis(),
+                sessionInfo.methodPath, System.currentTimeMillis(),
                 false /*isStartedFromActiveSession*/, null);
         externalSession.setIsExternal(true);
         // Mark the external session as already completed, since we have no way of knowing when
@@ -190,8 +191,6 @@ public class SessionManager {
         // Create a subsession from this external Session parent node
         Session childSession = createSubsession();
         continueSession(childSession, shortMethodName);
-
-        Log.d(LOGGING_TAG, Session.START_SESSION);
     }
 
     /**