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

Commit 2cfd96e2 authored by Nicolo' Mazzucato's avatar Nicolo' Mazzucato
Browse files

Introduce a way to debug relayouts and slow measures/layout

This cl introduces a way to debug 2 different but related things:

(1) Which classes suffer from long measure and layout pass
(2) What caused those classes to be re-measured/re-layout

In the current form, only sysui sets the flags to enable the above based on some sysprop.

(1) is enabled by `adb shell setprop persist.debug.trace_layouts 1` for all classes in sysui process (note: the process needs to restart). The ideal workflow is to first enable this to spot which are the main classes have long measure/layout slices. Once those are identified (e.g. class X)

(2) `adb shell setprop persist.debug.trace_request_layout_class X` enables requestLayout tracing for class X. At this point, every time requestLayout is called on that class, both an instant event (visible in perfetto) and the stacktrace (in logcat) is output.

After recording at perfetto trace with (2) enabled, it's possible to aggregate data with an SQL query in ui.perfetto.dev: For example, with the following we can have the most common relayout reasons:
```
SELECT count(*) cnt, msg
FROM android_logs
WHERE msg LIKE "requestLayout %"
GROUP BY msg
ORDER BY cnt DESC
```

The following helper bash function makes the above more efficient:

trace_class_layouts() {
        adb shell setprop persist.debug.trace_layouts 1
        adb shell setprop persist.debug.trace_request_layout_class $1

        adb shell am force-stop com.google.android.apps.nexuslauncher
        adb shell am force-stop com.android.systemui
}

Then, use `trace_class_layouts X` and record a perfetto trace.

To reduce the overhead, several strings are cached when the view is attached to the window. However, it should be noted that enabling this can have an impact on performance and should only be used for debugging purposes.

Test: record a trace after enabling options
Bug: 266090955
Change-Id: I89a518d4f3c69c13cdced0f70d8a1e2793bc923a
parent 46db4793
Loading
Loading
Loading
Loading
+2 −1
Original line number Diff line number Diff line
@@ -110,7 +110,8 @@ public final class Trace {
    public static final long TRACE_TAG_THERMAL = 1L << 27;

    private static final long TRACE_TAG_NOT_READY = 1L << 63;
    private static final int MAX_SECTION_NAME_LEN = 127;
    /** @hide **/
    public static final int MAX_SECTION_NAME_LEN = 127;

    // Must be volatile to avoid word tearing.
    // This is only kept in case any apps get this by reflection but do not
+148 −5
Original line number Diff line number Diff line
@@ -17,6 +17,7 @@
package android.view;
import static android.content.res.Resources.ID_NULL;
import static android.os.Trace.TRACE_TAG_APP;
import static android.view.ContentInfo.SOURCE_DRAG_AND_DROP;
import static android.view.accessibility.AccessibilityEvent.CONTENT_CHANGE_TYPE_UNDEFINED;
import static android.view.displayhash.DisplayHashResultCallback.DISPLAY_HASH_ERROR_INVALID_BOUNDS;
@@ -997,6 +998,22 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
     */
    private static boolean sAcceptZeroSizeDragShadow;
    /**
     * When true, measure and layout passes of all the newly attached views will be logged with
     * {@link Trace}, so we can better debug jank due to complex view hierarchies.
     */
    private static boolean sTraceLayoutSteps;
    /**
     * When not null, emits a {@link Trace} instant event and the stacktrace every time a relayout
     * of a class having this name happens.
     */
    private static String sTraceRequestLayoutClass;
    /** Used to avoid computing the full strings each time when layout tracing is enabled. */
    @Nullable
    private ViewTraversalTracingStrings mTracingStrings;
    /**
     * Prior to R, {@link #dispatchApplyWindowInsets} had an issue:
     * <p>The modified insets changed by {@link #onApplyWindowInsets} were passed to the
@@ -3583,6 +3600,9 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
     *                  1               PFLAG4_HAS_TRANSLATION_TRANSIENT_STATE
     *                 1                PFLAG4_DRAG_A11Y_STARTED
     *                1                 PFLAG4_AUTO_HANDWRITING_INITIATION_ENABLED
     *               1                  PFLAG4_IMPORTANT_FOR_CREDENTIAL_MANAGER
     *              1                   PFLAG4_TRAVERSAL_TRACING_ENABLED
     *             1                    PFLAG4_RELAYOUT_TRACING_ENABLED
     * |-------|-------|-------|-------|
     */
@@ -3669,6 +3689,18 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
     */
    private static final int PFLAG4_IMPORTANT_FOR_CREDENTIAL_MANAGER = 0x000020000;
    /**
     * When set, measure and layout passes of this view will be logged with {@link Trace}, so we
     * can better debug jank due to complex view hierarchies.
     */
    private static final int PFLAG4_TRAVERSAL_TRACING_ENABLED = 0x000040000;
    /**
     * When set, emits a {@link Trace} instant event and stacktrace every time a requestLayout of
     * this class happens.
     */
    private static final int PFLAG4_RELAYOUT_TRACING_ENABLED = 0x000080000;
    /* End of masks for mPrivateFlags4 */
    /** @hide */
@@ -6653,6 +6685,15 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
        out.append(mRight);
        out.append(',');
        out.append(mBottom);
        appendId(out);
        if (mAutofillId != null) {
            out.append(" aid="); out.append(mAutofillId);
        }
        out.append("}");
        return out.toString();
    }
    void appendId(StringBuilder out) {
        final int id = getId();
        if (id != NO_ID) {
            out.append(" #");
@@ -6684,11 +6725,6 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
                }
            }
        }
        if (mAutofillId != null) {
            out.append(" aid="); out.append(mAutofillId);
        }
        out.append("}");
        return out.toString();
    }
    /**
@@ -21154,6 +21190,14 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
        if (isFocused()) {
            notifyFocusChangeToImeFocusController(true /* hasFocus */);
        }
        if (sTraceLayoutSteps) {
            setTraversalTracingEnabled(true);
        }
        if (sTraceRequestLayoutClass != null
                && sTraceRequestLayoutClass.equals(getClass().getSimpleName())) {
            setRelayoutTracingEnabled(true);
        }
    }
    /**
@@ -24053,6 +24097,30 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
        return o instanceof ViewGroup && ((ViewGroup) o).isLayoutModeOptical();
    }
    /**
     * Enable measure/layout debugging on traces.
     *
     * @see Trace
     * @hide
     */
    public static void setTraceLayoutSteps(boolean traceLayoutSteps) {
        sTraceLayoutSteps = traceLayoutSteps;
    }
    /**
     * Enable request layout tracing classes with {@code s} simple name.
     * <p>
     * When set, a {@link Trace} instant event and a log with the stacktrace is emitted every
     * time a requestLayout of a class matching {@code s} name happens.
     * This applies only to views attached from this point onwards.
     *
     * @see Trace#instant(long, String)
     * @hide
     */
    public static void setTracedRequestLayoutClassClass(String s) {
        sTraceRequestLayoutClass = s;
    }
    private boolean setOpticalFrame(int left, int top, int right, int bottom) {
        Insets parentInsets = mParent instanceof View ?
                ((View) mParent).getOpticalInsets() : Insets.NONE;
@@ -24087,7 +24155,13 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
    @SuppressWarnings({"unchecked"})
    public void layout(int l, int t, int r, int b) {
        if ((mPrivateFlags3 & PFLAG3_MEASURE_NEEDED_BEFORE_LAYOUT) != 0) {
            if (isTraversalTracingEnabled()) {
                Trace.beginSection(mTracingStrings.onMeasureBeforeLayout);
            }
            onMeasure(mOldWidthMeasureSpec, mOldHeightMeasureSpec);
            if (isTraversalTracingEnabled()) {
                Trace.endSection();
            }
            mPrivateFlags3 &= ~PFLAG3_MEASURE_NEEDED_BEFORE_LAYOUT;
        }
@@ -24100,7 +24174,13 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
                setOpticalFrame(l, t, r, b) : setFrame(l, t, r, b);
        if (changed || (mPrivateFlags & PFLAG_LAYOUT_REQUIRED) == PFLAG_LAYOUT_REQUIRED) {
            if (isTraversalTracingEnabled()) {
                Trace.beginSection(mTracingStrings.onLayout);
            }
            onLayout(changed, l, t, r, b);
            if (isTraversalTracingEnabled()) {
                Trace.endSection();
            }
            if (shouldDrawRoundScrollbar()) {
                if(mRoundScrollbarRenderer == null) {
@@ -26660,6 +26740,25 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
        return (viewRoot != null && viewRoot.isInLayout());
    }
    /** To be used only for debugging purposes. */
    private void printStackStrace(String name) {
        Log.d(VIEW_LOG_TAG, "---- ST:" + name);
        StringBuilder sb = new StringBuilder();
        StackTraceElement[] stackTraceElements = Thread.currentThread().getStackTrace();
        int startIndex = 1;
        int endIndex = Math.min(stackTraceElements.length, startIndex + 20); // max 20 entries.
        for (int i = startIndex; i < endIndex; i++) {
            StackTraceElement s = stackTraceElements[i];
            sb.append(s.getMethodName())
                    .append("(")
                    .append(s.getFileName())
                    .append(":")
                    .append(s.getLineNumber())
                    .append(") <- ");
        }
        Log.d(VIEW_LOG_TAG, name + ": " + sb);
    }
    /**
     * Call this when something has changed which has invalidated the
     * layout of this view. This will schedule a layout pass of the view
@@ -26673,6 +26772,12 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
     */
    @CallSuper
    public void requestLayout() {
        if (isRelayoutTracingEnabled()) {
            Trace.instantForTrack(TRACE_TAG_APP, "requestLayoutTracing",
                    mTracingStrings.classSimpleName);
            printStackStrace(mTracingStrings.requestLayoutStacktracePrefix);
        }
        if (mMeasureCache != null) mMeasureCache.clear();
        if (mAttachInfo != null && mAttachInfo.mViewRequestingLayout == null) {
@@ -26766,8 +26871,14 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
            int cacheIndex = forceLayout ? -1 : mMeasureCache.indexOfKey(key);
            if (cacheIndex < 0 || sIgnoreMeasureCache) {
                if (isTraversalTracingEnabled()) {
                    Trace.beginSection(mTracingStrings.onMeasure);
                }
                // measure ourselves, this should set the measured dimension flag back
                onMeasure(widthMeasureSpec, heightMeasureSpec);
                if (isTraversalTracingEnabled()) {
                    Trace.endSection();
                }
                mPrivateFlags3 &= ~PFLAG3_MEASURE_NEEDED_BEFORE_LAYOUT;
            } else {
                long value = mMeasureCache.valueAt(cacheIndex);
@@ -32004,6 +32115,38 @@ public class View implements Drawable.Callback, KeyEvent.Callback,
                .isStylusHandwritingAvailable();
    }
    private void setTraversalTracingEnabled(boolean enabled) {
        if (enabled) {
            if (mTracingStrings == null) {
                mTracingStrings = new ViewTraversalTracingStrings(this);
            }
            mPrivateFlags4 |= PFLAG4_TRAVERSAL_TRACING_ENABLED;
        } else {
            mPrivateFlags4 &= ~PFLAG4_TRAVERSAL_TRACING_ENABLED;
        }
    }
    private boolean isTraversalTracingEnabled() {
        return (mPrivateFlags4 & PFLAG4_TRAVERSAL_TRACING_ENABLED)
                == PFLAG4_TRAVERSAL_TRACING_ENABLED;
    }
    private void setRelayoutTracingEnabled(boolean enabled) {
        if (enabled) {
            if (mTracingStrings == null) {
                mTracingStrings = new ViewTraversalTracingStrings(this);
            }
            mPrivateFlags4 |= PFLAG4_RELAYOUT_TRACING_ENABLED;
        } else {
            mPrivateFlags4 &= ~PFLAG4_RELAYOUT_TRACING_ENABLED;
        }
    }
    private boolean isRelayoutTracingEnabled() {
        return (mPrivateFlags4 & PFLAG4_RELAYOUT_TRACING_ENABLED)
                == PFLAG4_RELAYOUT_TRACING_ENABLED;
    }
    /**
     * Collects a {@link ViewTranslationRequest} which represents the content to be translated in
     * the view.
+63 −0
Original line number Diff line number Diff line
/*
 * Copyright (C) 2023 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 android.view;

import android.os.Trace;

/**
 * Keeps and caches strings used to trace {@link View} traversals.
 * <p>
 * This is done to avoid expensive computations of them every time, which can improve performance.
 */
class ViewTraversalTracingStrings {

    /** {@link Trace} tag used to mark {@link View#onMeasure(int, int)}. */
    public final String onMeasure;

    /** {@link Trace} tag used to mark {@link View#onLayout(boolean, int, int, int, int)}. */
    public final String onLayout;

    /** Caches the view simple name to avoid re-computations. */
    public final String classSimpleName;

    /** Prefix for request layout stacktraces output in logs. */
    public final String requestLayoutStacktracePrefix;

    /** {@link Trace} tag used to mark {@link View#onMeasure(int, int)} happening before layout. */
    public final String onMeasureBeforeLayout;

    /**
     * @param v {@link View} from where to get the class name.
     */
    ViewTraversalTracingStrings(View v) {
        String className = v.getClass().getSimpleName();
        classSimpleName = className;
        onMeasureBeforeLayout = getTraceName("onMeasureBeforeLayout", className, v);
        onMeasure = getTraceName("onMeasure", className, v);
        onLayout = getTraceName("onLayout", className, v);
        requestLayoutStacktracePrefix = "requestLayout " + className;
    }

    private String getTraceName(String sectionName, String className, View v) {
        StringBuilder out = new StringBuilder();
        out.append(sectionName);
        out.append(" ");
        out.append(className);
        v.appendId(out);
        return out.substring(0, Math.min(out.length() - 1, Trace.MAX_SECTION_NAME_LEN - 1));
    }
}
+6 −0
Original line number Diff line number Diff line
@@ -38,6 +38,7 @@ import android.util.Log;
import android.util.TimingsTraceLog;
import android.view.SurfaceControl;
import android.view.ThreadedRenderer;
import android.view.View;

import com.android.internal.protolog.common.ProtoLog;
import com.android.systemui.dagger.GlobalRootComponent;
@@ -112,6 +113,11 @@ public class SystemUIApplication extends Application implements
        // the theme set there.
        setTheme(R.style.Theme_SystemUI);

        View.setTraceLayoutSteps(
                SystemProperties.getBoolean("persist.debug.trace_layouts", false));
        View.setTracedRequestLayoutClassClass(
                SystemProperties.get("persist.debug.trace_request_layout_class", null));

        if (Process.myUserHandle().equals(UserHandle.SYSTEM)) {
            IntentFilter bootCompletedFilter = new
                    IntentFilter(Intent.ACTION_LOCKED_BOOT_COMPLETED);