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

Commit fd9d6a09 authored by Lee Shombert's avatar Lee Shombert
Browse files

Add anr tracing to AnrTimerService 

This change allows user to configure tracing on ANR timers for
specified processes.  Configuration is through the `am` shell command;
it is meant to be used by application or system developers - not by
end users.  When a timer is traced, extra actions can be executed at
the "split point" - an early timeout specified as a percentage of the
originally programmed timeout.  Information at the early timeout helps
developers analyze current or incipient ANRs.

Tested by manually generating an ANR (using a custom app) and
verifying that the expected perfetto trace events were created or
that the timer expired, as appropriate.

The command to generate trace points on a process's timer is:
`adb shell am trace-timer name="anrtimer.receiver"`

The command to generate tracepoints and expire a timer at the 20% point is:
`adb shell am trace-timer name="anrtimer.receiver" expire=20`

The command to disable tracing, if it was ever enabled, is:
`adb shell am trace-timer off`

Bug: 352085328
Flag: com.android.server.utils.anr_timer_trace
Test: atest
 * FrameworksServicesTests:com.android.server.am
 * FrameworksServicesTests:AnrTimerTest
Change-Id: Ibc30f1f488baff056225671f063f026ce30e2e6f
parent feaa25f8

services/core/java/com/android/server/am/ActivityManagerShellCommand.java

+36 −0
Original line number Diff line number Diff line
@@ -133,6 +133,7 @@ import com.android.server.am.nano.VMCapability; 
import com.android.server.am.nano.VMInfo;

import com.android.server.compat.PlatformCompat;

import com.android.server.pm.UserManagerInternal;

import com.android.server.utils.AnrTimer;

import com.android.server.utils.Slogf;



import dalvik.annotation.optimization.NeverCompile;
@@ -285,6 +286,8 @@ final class ActivityManagerShellCommand extends ShellCommand { 
                    return -1;

                case "trace-ipc":

                    return runTraceIpc(pw);

                case "trace-timer":

                    return runTraceTimer(pw);

                case "profile":

                    return runProfile(pw);

                case "dumpheap":
@@ -1062,6 +1065,23 @@ final class ActivityManagerShellCommand extends ShellCommand { 
        return 0;

    }



    // Update AnrTimer tracing.

    private int runTraceTimer(PrintWriter pw) throws RemoteException {

        if (!AnrTimer.traceFeatureEnabled()) return -1;



        // Delegate all argument parsing to the AnrTimer method.

        try {

            final String result = AnrTimer.traceTimers(peekRemainingArgs());

            if (result != null) {

                pw.println(result);

            }

            return 0;

        } catch (IllegalArgumentException e) {

            getErrPrintWriter().println("Error: bad trace-timer command: " + e);

            return -1;

        }

    }



    // NOTE: current profiles can only be started on default display (even on automotive builds with

    // passenger displays), so there's no need to pass a display-id

    private int runProfile(PrintWriter pw) throws RemoteException {
@@ -4352,6 +4372,7 @@ final class ActivityManagerShellCommand extends ShellCommand { 
            pw.println("      start: start tracing IPC transactions.");

            pw.println("      stop: stop tracing IPC transactions and dump the results to file.");

            pw.println("      --dump-file <FILE>: Specify the file the trace should be dumped to.");

            anrTimerHelp(pw);

            pw.println("  profile start [--user <USER_ID> current]");

            pw.println("          [--clock-type <TYPE>]");

            pw.println("          [" + PROFILER_OUTPUT_VERSION_FLAG + " VERSION]");
@@ -4605,4 +4626,19 @@ final class ActivityManagerShellCommand extends ShellCommand { 
            Intent.printIntentArgsHelp(pw, "");

        }

    }



    static void anrTimerHelp(PrintWriter pw) {

        // Return silently if tracing is not feature-enabled.

        if (!AnrTimer.traceFeatureEnabled()) return;



        String h = AnrTimer.traceTimers(new String[]{"help"});

        if (h == null) {

            return;

        }



        pw.println("  trace-timer <cmd>");

        for (String s : h.split("\n")) {

            pw.println("         " + s);

        }

    }

}

services/core/java/com/android/server/utils/AnrTimer.java

+45 −11
Original line number Diff line number Diff line
@@ -130,22 +130,35 @@ public abstract class AnrTimer<V> implements AutoCloseable { 
    }



    /**

     * Return true if freezing is enabled.  This has no effect if the service is not enabled.

     * Return true if freezing is feature-enabled.  Freezing must still be enabled on a

     * per-service basis.

     */

    private static boolean anrTimerFreezerEnabled() {

    private static boolean freezerFeatureEnabled() {

        return Flags.anrTimerFreezer();

    }



    /**

     * Return true if tracing is feature-enabled.  This has no effect unless tracing is configured.

     * Note that this does not represent any per-process overrides via an Injector.

     */

    public static boolean traceFeatureEnabled() {

        return anrTimerServiceEnabled() && Flags.anrTimerTrace();

    }



    /**

     * This class allows test code to provide instance-specific overrides.

     */

    static class Injector {

        boolean anrTimerServiceEnabled() {

        boolean serviceEnabled() {

            return AnrTimer.anrTimerServiceEnabled();

        }



        boolean anrTimerFreezerEnabled() {

            return AnrTimer.anrTimerFreezerEnabled();

        boolean freezerEnabled() {

            return AnrTimer.freezerFeatureEnabled();

        }



        boolean traceEnabled() {

            return AnrTimer.traceFeatureEnabled();

        }

    }
@@ -349,7 +362,7 @@ public abstract class AnrTimer<V> implements AutoCloseable { 
        mWhat = what;

        mLabel = label;

        mArgs = args;

        boolean enabled = args.mInjector.anrTimerServiceEnabled() && nativeTimersSupported();

        boolean enabled = args.mInjector.serviceEnabled() && nativeTimersSupported();

        mFeature = createFeatureSwitch(enabled);

    }
@@ -448,7 +461,7 @@ public abstract class AnrTimer<V> implements AutoCloseable { 


    /**

     * The FeatureDisabled class bypasses almost all AnrTimer logic.  It is used when the AnrTimer

     * service is disabled via Flags.anrTimerServiceEnabled.

     * service is disabled via Flags.anrTimerService().

     */

    private class FeatureDisabled extends FeatureSwitch {

        /** Start a timer by sending a message to the client's handler. */
@@ -515,7 +528,7 @@ public abstract class AnrTimer<V> implements AutoCloseable { 


    /**

     * The FeatureEnabled class enables the AnrTimer logic.  It is used when the AnrTimer service

     * is enabled via Flags.anrTimerServiceEnabled.

     * is enabled via Flags.anrTimerService().

     */

    private class FeatureEnabled extends FeatureSwitch {
@@ -533,7 +546,7 @@ public abstract class AnrTimer<V> implements AutoCloseable { 
        FeatureEnabled() {

            mNative = nativeAnrTimerCreate(mLabel,

                    mArgs.mExtend,

                    mArgs.mFreeze && mArgs.mInjector.anrTimerFreezerEnabled());

                    mArgs.mFreeze && mArgs.mInjector.freezerEnabled());

            if (mNative == 0) throw new IllegalArgumentException("unable to create native timer");

            synchronized (sAnrTimerList) {

                sAnrTimerList.put(mNative, new WeakReference(AnrTimer.this));
@@ -550,7 +563,7 @@ public abstract class AnrTimer<V> implements AutoCloseable { 
                // exist.

                if (cancel(arg)) mTotalRestarted++;



                int timerId = nativeAnrTimerStart(mNative, pid, uid, timeoutMs);

                final int timerId = nativeAnrTimerStart(mNative, pid, uid, timeoutMs);

                if (timerId > 0) {

                    mTimerIdMap.put(arg, timerId);

                    mTimerArgMap.put(timerId, arg);
@@ -895,7 +908,7 @@ public abstract class AnrTimer<V> implements AutoCloseable { 
    /** Dumpsys output, allowing for overrides. */

    @VisibleForTesting

    static void dump(@NonNull PrintWriter pw, boolean verbose, @NonNull Injector injector) {

        if (!injector.anrTimerServiceEnabled()) return;

        if (!injector.serviceEnabled()) return;



        final IndentingPrintWriter ipw = new IndentingPrintWriter(pw);

        ipw.println("AnrTimer statistics");
@@ -925,6 +938,18 @@ public abstract class AnrTimer<V> implements AutoCloseable { 
        dump(pw, verbose, sDefaultInjector);

    }



    /**

     * Set a trace specification.  The input is a set of strings.  On success, the function pushes

     * the trace specification to all timers, and then returns a response message.  On failure,

     * the function throws IllegalArgumentException and tracing is disabled.

     *

     * An empty specification has no effect other than returning the current trace specification.

     */

    @Nullable

    public static String traceTimers(@Nullable String[] spec) {

        return nativeAnrTimerTrace(spec);

    }



    /**

     * Return true if the native timers are supported.  Native timers are supported if the method

     * nativeAnrTimerSupported() can be executed and it returns true.
@@ -981,6 +1006,15 @@ public abstract class AnrTimer<V> implements AutoCloseable { 
     */

    private static native boolean nativeAnrTimerRelease(long service, int timerId);



    /**

     * Configure tracing.  The input array is a set of words pulled from the command line.  All

     * parsing happens inside the native layer.  The function returns a string which is either an

     * error message (so nothing happened) or the current configuration after applying the config.

     * Passing an null array or an empty array simply returns the current configuration.

     * The function returns null if the native layer is not implemented.

     */

    private static native @Nullable String nativeAnrTimerTrace(@Nullable String[] config);



    /** Retrieve runtime dump information from the native layer. */

    private static native String[] nativeAnrTimerDump(long service);

}

services/core/java/com/android/server/utils/flags.aconfig

+7 −0
Original line number Diff line number Diff line
@@ -17,3 +17,10 @@ flag { 
     bug: "325594551"

}



flag {

     name: "anr_timer_trace"

     namespace: "system_performance"

     is_fixed_read_only: true

     description: "When true, start a trace if an ANR timer reaches 50%"

     bug: "352085328"

}

services/core/jni/com_android_server_utils_AnrTimer.cpp

+434 −73

File changed.

Preview size limit exceeded, changes collapsed.

services/tests/servicestests/src/com/android/server/utils/AnrTimerTest.java

+1 −1
Original line number Diff line number Diff line
@@ -119,7 +119,7 @@ public class AnrTimerTest { 
     */

    private class TestInjector extends AnrTimer.Injector {

        @Override

        boolean anrTimerServiceEnabled() {

        boolean serviceEnabled() {

            return mEnabled;

        }

    }