Readability improvements in Logging
We now truncate Session method paths and IDs based on the Logging level
to improve Session Logging readability in logcat. If another external
session is started off of an existing external Session, the preceding
histories are replaced with "..." so that the Session information is not
overwhelming.
Bug: 26571395
Test: Unit Tests and manual tests pass
Change-Id: I9ffda3d64f1072fa6228a82a86116a5e47d18c96
diff --git a/telecomm/java/android/telecom/ConnectionService.java b/telecomm/java/android/telecom/ConnectionService.java
index 66d704b..f177a41 100644
--- a/telecomm/java/android/telecom/ConnectionService.java
+++ b/telecomm/java/android/telecom/ConnectionService.java
@@ -515,9 +515,12 @@
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 @@
isIncoming,
isUnknown);
}
- });
+ }.prepare());
} else {
createConnection(
connectionManagerPhoneAccount,
@@ -1378,9 +1381,9 @@
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 @@
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());
}
});
}
diff --git a/telecomm/java/android/telecom/Log.java b/telecomm/java/android/telecom/Log.java
index 446bbbb..ced6627 100644
--- a/telecomm/java/android/telecom/Log.java
+++ b/telecomm/java/android/telecom/Log.java
@@ -48,13 +48,13 @@
// 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 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);
}
/**
diff --git a/telecomm/java/android/telecom/Logging/Runnable.java b/telecomm/java/android/telecom/Logging/Runnable.java
index 56c52bf..6e81053 100644
--- a/telecomm/java/android/telecom/Logging/Runnable.java
+++ b/telecomm/java/android/telecom/Logging/Runnable.java
@@ -27,7 +27,7 @@
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 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;
}
@@ -85,4 +96,4 @@
*/
abstract public void loggedRun();
-}
+}
\ No newline at end of file
diff --git a/telecomm/java/android/telecom/Logging/Session.java b/telecomm/java/android/telecom/Logging/Session.java
index 3a7b8c0..c45bd6b 100644
--- a/telecomm/java/android/telecom/Logging/Session.java
+++ b/telecomm/java/android/telecom/Logging/Session.java
@@ -19,6 +19,7 @@
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 java.util.ArrayList;
/**
- * The session that stores information about a thread's point of entry into the Telecom code that
- * persists until the thread exits Telecom.
+ * Stores information about a thread's point of entry into that should persist until that thread
+ * 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 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 @@
@Override
public void writeToParcel(Parcel destination, int flags) {
destination.writeString(sessionId);
- destination.writeString(shortMethodName);
+ destination.writeString(methodPath);
}
}
@@ -226,7 +234,15 @@
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 @@
}
// 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.
- public String getFullMethodPath() {
+ // path. if truncatePath is set to true, all other external sessions (except for the most
+ // 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) {
- // Don't calculate if we have already figured it out!
- if (!TextUtils.isEmpty(mFullMethodPathCache)) {
+ private synchronized void getFullMethodPath(StringBuilder sb, boolean truncatePath) {
+ // Return cached value for method path. When returning the truncated path, recalculate the
+ // full path without using the cached value.
+ if (!TextUtils.isEmpty(mFullMethodPathCache) && !truncatePath) {
sb.append(mFullMethodPathCache);
return;
}
@@ -278,25 +296,37 @@
// 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()) {
- sb.append("(");
- sb.append(mShortMethodName);
- sb.append(")");
+ if (truncatePath) {
+ sb.append(TRUNCATE_STRING);
+ } else {
+ sb.append("(");
+ sb.append(mShortMethodName);
+ sb.append(")");
+ }
} else {
sb.append(mShortMethodName);
}
-
- if(isSessionStarted) {
+ // If we are returning the truncated path, do not save that path as the full path.
+ 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 @@
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);
diff --git a/telecomm/java/android/telecom/Logging/SessionManager.java b/telecomm/java/android/telecom/Logging/SessionManager.java
index 8ced7f81..949f7b7 100644
--- a/telecomm/java/android/telecom/Logging/SessionManager.java
+++ b/telecomm/java/android/telecom/Logging/SessionManager.java
@@ -177,8 +177,9 @@
}
// 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 @@
// Create a subsession from this external Session parent node
Session childSession = createSubsession();
continueSession(childSession, shortMethodName);
-
- Log.d(LOGGING_TAG, Session.START_SESSION);
}
/**