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

Commit 502ec9aa authored by John Wu's avatar John Wu Committed by Android (Google) Code Review
Browse files

Merge changes I02730000,I2b4742de into main

* changes:
  [Ravenwood] Move all error related code into RavenwoodErrorHandler
  [Ravenwood] Allow signal USR1 to trigger bug report
parents 8b7dffcb c8d61770
Loading
Loading
Loading
Loading
+3 −157
Original line number Diff line number Diff line
@@ -58,16 +58,11 @@ import org.junit.runner.Description;
import java.io.File;
import java.io.IOException;
import java.io.PrintStream;
import java.util.Comparator;
import java.util.HashMap;
import java.util.Locale;
import java.util.Map;
import java.util.Objects;
import java.util.Random;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ScheduledFuture;
import java.util.concurrent.TimeUnit;
import java.util.regex.Pattern;
import java.util.stream.Collectors;

@@ -105,41 +100,10 @@ public class RavenwoodDriver {
    private static final String ANDROID_LOG_TAGS = "ANDROID_LOG_TAGS";
    private static final String RAVENWOOD_ANDROID_LOG_TAGS = "RAVENWOOD_" + ANDROID_LOG_TAGS;

    /**
     * When enabled, attempt to dump all thread stacks just before we hit the
     * overall Tradefed timeout, to aid in debugging deadlocks.
     *
     * Note, this timeout will _not_ stop the test, as there isn't really a clean way to do it.
     * It'll merely print stacktraces.
     */
    private static final boolean ENABLE_TIMEOUT_STACKS =
            !"0".equals(System.getenv("RAVENWOOD_ENABLE_TIMEOUT_STACKS"));

    static final int DEFAULT_TIMEOUT_SECONDS = 10;
    private static final int TIMEOUT_MILLIS = getTimeoutSeconds() * 1000;

    /** Do not dump environments matching this pattern. */
    private static final Pattern sSecretEnvPattern = Pattern.compile(
            "(KEY|AUTH|API)", Pattern.CASE_INSENSITIVE);

    private static int getTimeoutSeconds() {
        var e = System.getenv("RAVENWOOD_TIMEOUT_SECONDS");
        if (e == null || e.isEmpty()) {
            return DEFAULT_TIMEOUT_SECONDS;
        }
        return Integer.parseInt(e);
    }

    private static final ScheduledExecutorService sTimeoutExecutor =
            Executors.newScheduledThreadPool(1, (Runnable r) -> {
                Thread t = Executors.defaultThreadFactory().newThread(r);
                t.setName("Ravenwood:TimeoutMonitor");
                t.setDaemon(true);
                return t;
            });

    private static volatile ScheduledFuture<?> sPendingTimeout;

    // TODO: expose packCallingIdentity function in libbinder and use it directly
    // See: packCallingIdentity in frameworks/native/libs/binder/IPCThreadState.cpp
    static long packBinderIdentityToken(
@@ -204,10 +168,8 @@ public class RavenwoodDriver {
        // We haven't initialized liblog yet, so directly write to System.out here.
        RavenwoodInternalUtils.log(TAG, "globalInitInner()");

        if (RavenwoodErrorHandler.ENABLE_UNCAUGHT_EXCEPTION_DETECTION) {
            Thread.setDefaultUncaughtExceptionHandler(
                    new RavenwoodErrorHandler.UncaughtExceptionHandler());
        }
        // Set up global error handling infrastructure
        RavenwoodErrorHandler.init();

        // Some process-wide initialization:
        // - maybe redirect stdout/stderr
@@ -328,48 +290,9 @@ public class RavenwoodDriver {
     * Called when a test method is about to be started.
     */
    public static void enterTestMethod(Description description) {

        RavenwoodErrorHandler.sCurrentDescription = description;

        // If an uncaught exception has been detected, don't run subsequent test methods
        // in the same test.
        RavenwoodErrorHandler.maybeThrowUnrecoverableUncaughtException();

        // TODO(b/375272444): this is a hacky workaround to ensure binder identity
        Binder.restoreCallingIdentity(
                RavenwoodEnvironment.getInstance().getDefaultCallingIdentity());

        scheduleTimeout();
    }

    /**
     * Called when a test method finished.
     */
    public static void exitTestMethod(Description description) {
        cancelTimeout();
        RavenwoodErrorHandler.maybeThrowPendingRecoverableUncaughtExceptionAndClear();
        RavenwoodErrorHandler.maybeThrowUnrecoverableUncaughtException();
    }

    private static void scheduleTimeout() {
        if (!ENABLE_TIMEOUT_STACKS) {
            return;
        }
        cancelTimeout();

        sPendingTimeout = sTimeoutExecutor.schedule(
                RavenwoodDriver::onTestTimedOut,
                TIMEOUT_MILLIS, TimeUnit.MILLISECONDS);
    }

    private static void cancelTimeout() {
        if (!ENABLE_TIMEOUT_STACKS) {
            return;
        }
        var pt = sPendingTimeout;
        if (pt != null) {
            pt.cancel(false);
        }
    }

    private static void initializeCompatIds() {
@@ -399,74 +322,6 @@ public class RavenwoodDriver {
        AppCompatCallbacks.install(disabledChanges, loggableChanges, false);
    }

    /**
     * A callback when a test class finishes its execution.
     */
    public static void exitTestClass() {
        RavenwoodErrorHandler.maybeThrowPendingRecoverableUncaughtExceptionAndClear();
    }

    /**
     * Prints the stack trace from all threads.
     */
    private static void onTestTimedOut() {
        sRawStdErr.println("********* SLOW TEST DETECTED ********");
        dumpStacks(null, null);
    }

    private static final Object sDumpStackLock = new Object();

    /**
     * Prints the stack trace from all threads.
     */
    private static void dumpStacks(
            @Nullable Thread exceptionThread, @Nullable Throwable throwable) {
        cancelTimeout();
        synchronized (sDumpStackLock) {
            final PrintStream out = sRawStdErr;
            out.println("-----BEGIN ALL THREAD STACKS-----");

            var stacks = Thread.getAllStackTraces();
            var threads = stacks.keySet().stream().sorted(
                    Comparator.comparingLong(Thread::getId)).collect(Collectors.toList());

            // Put the test and the main thread at the top.
            var env = RavenwoodEnvironment.getInstance();
            var testThread = env.getTestThread();
            var mainThread = env.getMainThread();
            if (mainThread != null) {
                threads.remove(mainThread);
                threads.add(0, mainThread);
            }
            if (testThread != null) {
                threads.remove(testThread);
                threads.add(0, testThread);
            }
            // Put the exception thread at the top.
            // Also inject the stacktrace from the exception.
            if (exceptionThread != null) {
                threads.remove(exceptionThread);
                threads.add(0, exceptionThread);
                stacks.put(exceptionThread, throwable.getStackTrace());
            }
            for (var th : threads) {
                out.println();

                out.print("Thread");
                if (th == exceptionThread) {
                    out.print(" [** EXCEPTION THREAD **]");
                }
                out.print(": " + th.getName() + " / " + th);
                out.println();

                for (StackTraceElement e :  stacks.get(th)) {
                    out.println("\tat " + e);
                }
            }
            out.println("-----END ALL THREAD STACKS-----");
        }
    }

    private static final String MOCKITO_ERROR = "FATAL: Unsupported Mockito detected!"
            + " Your test or its dependencies use one of the \"mockito-target-*\""
            + " modules as static library, which is unusable on host side."
@@ -503,16 +358,6 @@ public class RavenwoodDriver {
        }
    }

    static void doBugreport(
            @Nullable Thread exceptionThread, @Nullable Throwable throwable,
            boolean killSelf) {
        // TODO: Print more information
        dumpStacks(exceptionThread, throwable);
        if (killSelf) {
            System.exit(13);
        }
    }

    private static void dumpJavaProperties() {
        Log.i(TAG, "JVM properties:");
        dumpMap(System.getProperties());
@@ -540,6 +385,7 @@ public class RavenwoodDriver {
            Log.i(TAG, "  " + key + "=" + map.get(key));
        }
    }

    private static void dumpOtherInfo() {
        Log.i(TAG, "Other key information:");
        var jloc = Locale.getDefault();
+175 −2
Original line number Diff line number Diff line
@@ -15,17 +15,28 @@
 */
package android.platform.test.ravenwood;

import static android.platform.test.ravenwood.RavenwoodDriver.sRawStdErr;

import android.annotation.NonNull;
import android.annotation.Nullable;
import android.os.Message;
import android.util.Log;

import com.android.ravenwood.OpenJdkWorkaround;
import com.android.ravenwood.common.RavenwoodInternalUtils;
import com.android.ravenwood.common.SneakyThrow;

import org.junit.AssumptionViolatedException;
import org.junit.runner.Description;

import java.io.PrintStream;
import java.util.Comparator;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ScheduledFuture;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicReference;
import java.util.stream.Collectors;

public class RavenwoodErrorHandler {
    private static final String TAG = RavenwoodInternalUtils.TAG;
@@ -52,6 +63,98 @@ public class RavenwoodErrorHandler {

    volatile static Description sCurrentDescription;

    // Several callbacks regarding test lifecycle

    static void init() {
        if (ENABLE_UNCAUGHT_EXCEPTION_DETECTION) {
            Thread.setDefaultUncaughtExceptionHandler(new UncaughtExceptionHandler());
        }

        // `pkill -USR1 -f tradefed-isolation.jar` will trigger a full thread dumps
        OpenJdkWorkaround.registerSignalHandler("USR1", () -> {
            sRawStdErr.println("-----SIGUSR1 HANDLER-----");
            RavenwoodErrorHandler.doBugreport(null, null, false);
        });
    }

    /**
     * Called when a test method is about to be started.
     */
    static void enterTestMethod(Description description) {
        sCurrentDescription = description;
        // If an uncaught exception has been detected, don't run subsequent test methods
        // in the same test.
        maybeThrowUnrecoverableUncaughtException();
        scheduleTimeout();
    }

    static void exitTestMethod(Description description) {
        cancelTimeout();
        maybeThrowPendingRecoverableUncaughtExceptionAndClear();
        maybeThrowUnrecoverableUncaughtException();
    }

    static void exitTestClass() {
        maybeThrowPendingRecoverableUncaughtExceptionAndClear();
    }

    // Setup timeout to detect slow tests

    /**
     * When enabled, attempt to dump all thread stacks just before we hit the
     * overall Tradefed timeout, to aid in debugging deadlocks.
     *
     * Note, this timeout will _not_ stop the test, as there isn't really a clean way to do it.
     * It'll merely print stacktraces.
     */
    private static final boolean ENABLE_TIMEOUT_STACKS =
            !"0".equals(System.getenv("RAVENWOOD_ENABLE_TIMEOUT_STACKS"));

    private static final int DEFAULT_TIMEOUT_SECONDS = 10;
    private static final int TIMEOUT_MILLIS = getTimeoutSeconds() * 1000;

    private static int getTimeoutSeconds() {
        var e = System.getenv("RAVENWOOD_TIMEOUT_SECONDS");
        if (e == null || e.isEmpty()) {
            return DEFAULT_TIMEOUT_SECONDS;
        }
        return Integer.parseInt(e);
    }

    private static final ScheduledExecutorService sTimeoutExecutor =
            Executors.newScheduledThreadPool(1, (Runnable r) -> {
                Thread t = Executors.defaultThreadFactory().newThread(r);
                t.setName("Ravenwood:TimeoutMonitor");
                t.setDaemon(true);
                return t;
            });

    private static volatile ScheduledFuture<?> sPendingTimeout;

    /**
     * Prints the stack trace from all threads.
     */
    private static void onTestTimedOut() {
        sRawStdErr.println("********* SLOW TEST DETECTED ********");
        dumpStacks(null, null);
    }

    private static void scheduleTimeout() {
        if (!ENABLE_TIMEOUT_STACKS) return;
        cancelTimeout();
        sPendingTimeout = sTimeoutExecutor.schedule(
                RavenwoodErrorHandler::onTestTimedOut,
                TIMEOUT_MILLIS, TimeUnit.MILLISECONDS);
    }

    private static void cancelTimeout() {
        var pt = sPendingTimeout;
        if (pt != null) {
            pt.cancel(false);
            sPendingTimeout = null;
        }
    }

    private static class RecoverableUncaughtException extends Exception {
        private RecoverableUncaughtException(String message, Throwable cause) {
            super(message, cause);
@@ -98,7 +201,7 @@ public class RavenwoodErrorHandler {
                return;
            }
            setPendingUnrecoverableUncaughtException(thread, inner);
            RavenwoodDriver.doBugreport(thread, inner, DIE_ON_UNCAUGHT_EXCEPTION);
            doBugreport(thread, inner, DIE_ON_UNCAUGHT_EXCEPTION);
        }
    }

@@ -125,7 +228,7 @@ public class RavenwoodErrorHandler {
        } catch (Throwable th) {
            var desc = String.format("Detected %s on looper thread %s", th.getClass().getName(),
                    Thread.currentThread());
            RavenwoodDriver.sRawStdErr.println(desc);
            sRawStdErr.println(desc);

            // If it's a tracked message, attach the stacktrace where we posted it as a cause.
            RavenwoodMessageTracker.getInstance().injectPosterAsCause(th, msg);
@@ -204,4 +307,74 @@ public class RavenwoodErrorHandler {
    public static void maybeThrowPendingRecoverableUncaughtExceptionNoClear() {
        maybeThrowPendingRecoverableUncaughtException(false);
    }

    // Dump all thread stack traces

    private static final Object sDumpStackLock = new Object();

    /**
     * Prints the stack trace from all threads.
     */
    private static void dumpStacks(
            @Nullable Thread exceptionThread, @Nullable Throwable throwable) {
        synchronized (sDumpStackLock) {
            final PrintStream out = sRawStdErr;
            out.println("-----BEGIN ALL THREAD STACKS-----");

            var desc = sCurrentDescription;
            if (desc != null) {
                out.format("Running test: %s:%s#%s\n",
                        RavenwoodEnvironment.getInstance().getTestModuleName(),
                        desc.getClassName(), desc.getMethodName());
            }

            var stacks = Thread.getAllStackTraces();
            var threads = stacks.keySet().stream().sorted(
                    Comparator.comparingLong(Thread::getId)).collect(Collectors.toList());

            // Put the test and the main thread at the top.
            var env = RavenwoodEnvironment.getInstance();
            var testThread = env.getTestThread();
            var mainThread = env.getMainThread();
            if (mainThread != null) {
                threads.remove(mainThread);
                threads.add(0, mainThread);
            }
            if (testThread != null) {
                threads.remove(testThread);
                threads.add(0, testThread);
            }
            // Put the exception thread at the top.
            // Also inject the stacktrace from the exception.
            if (exceptionThread != null) {
                threads.remove(exceptionThread);
                threads.add(0, exceptionThread);
                stacks.put(exceptionThread, throwable.getStackTrace());
            }
            for (var th : threads) {
                out.println();

                out.print("Thread");
                if (th == exceptionThread) {
                    out.print(" [** EXCEPTION THREAD **]");
                }
                out.print(": " + th.getName() + " / " + th);
                out.println();

                for (StackTraceElement e :  stacks.get(th)) {
                    out.println("\tat " + e);
                }
            }
            out.println("-----END ALL THREAD STACKS-----");
        }
    }

    static void doBugreport(
            @Nullable Thread exceptionThread, @Nullable Throwable throwable, boolean killSelf) {
        // TODO: Print more information
        dumpStacks(exceptionThread, throwable);
        if (killSelf) {
            System.exit(13);
        }
    }
}
+3 −6
Original line number Diff line number Diff line
@@ -62,8 +62,6 @@ public final class RavenwoodRunnerState {
        mRunner = runner;
    }

    private Description mMethodDescription;

    public void enterTestRunner() {
        if (RAVENWOOD_VERBOSE_LOGGING) {
            Log.v(TAG, "enterTestRunner: " + mRunner);
@@ -82,19 +80,18 @@ public final class RavenwoodRunnerState {
            Log.v(TAG, "exitTestClass: " + mRunner.mTestJavaClass.getName());
        }
        assertTrue(RAVENWOOD_RULE_ERROR, sActiveProperties.isEmpty());
        RavenwoodDriver.exitTestClass();
        RavenwoodErrorHandler.exitTestClass();
    }

    /** Called when a test method is about to start */
    public void enterTestMethod(Description description) {
        mMethodDescription = description;
        RavenwoodDriver.enterTestMethod(description);
        RavenwoodErrorHandler.enterTestMethod(description);
    }

    /** Called when a test method finishes */
    public void exitTestMethod(Description description) {
        RavenwoodDriver.exitTestMethod(description);
        mMethodDescription = null;
        RavenwoodErrorHandler.exitTestMethod(description);
    }

    public void enterRavenwoodRule(RavenwoodRule rule) {
+6 −0
Original line number Diff line number Diff line
@@ -23,6 +23,8 @@ import java.lang.reflect.InvocationTargetException;
import java.util.Map;
import java.util.WeakHashMap;

import sun.misc.Signal;

public class OpenJdkWorkaround {

    // @GuardedBy("sAddressMap")
@@ -89,4 +91,8 @@ public class OpenJdkWorkaround {
        }
        return null;
    }

    public static void registerSignalHandler(String signal, Runnable handler) {
        Signal.handle(new Signal(signal), sig -> handler.run());
    }
}