Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 0c3541be authored by Brad Ebinger's avatar Brad Ebinger
Browse files

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
parent 8631e19d
Loading
Loading
Loading
Loading
+12 −9
Original line number Diff line number Diff line
@@ -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());
            }
        });
    }
+10 −5
Original line number Diff line number Diff line
@@ -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);
    }

    /**
+14 −3
Original line number Diff line number Diff line
@@ -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;
    }

+52 −22
Original line number Diff line number Diff line
@@ -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
 * 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 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.
    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 @@ 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(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 @@ 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);
+2 −3
Original line number Diff line number Diff line
@@ -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);
    }

    /**