From c8dac37e3e93fc73df332e1723888344655fe413 Mon Sep 17 00:00:00 2001 From: Makoto Onuki Date: Fri, 21 Feb 2025 14:13:40 -0800 Subject: Multiple improvements - Sysprops allowlist now fully moved to the text file. - Always enable the test timeout w/ improved stack traces - Add a method to "run on main thread" - Always enable the uncaught exception handler. - Tolerate assertion failures on the main looper. (rather than letting it crash the thread) - Also some other minor changes needed in my main work. Flag: EXEMPT host test change only Bug: 292141694 Test: $ANDROID_BUILD_TOP/frameworks/base/ravenwood/scripts/run-ravenwood-tests.sh Change-Id: I47b060021ce46b6e9fbe4aca63835745311a4b06 --- .../test/ravenwood/RavenwoodAwareTestRunner.java | 17 +- .../test/ravenwood/RavenwoodRunnerState.java | 7 +- .../RavenwoodRuntimeEnvironmentController.java | 265 ++++++++++++++++----- .../test/ravenwood/RavenwoodSystemProperties.java | 83 ++++--- 4 files changed, 262 insertions(+), 110 deletions(-) (limited to 'ravenwood/junit-impl-src') diff --git a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodAwareTestRunner.java b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodAwareTestRunner.java index 3ebef02284d6..b6167665c985 100644 --- a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodAwareTestRunner.java +++ b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodAwareTestRunner.java @@ -23,13 +23,10 @@ import static org.junit.Assume.assumeTrue; import android.annotation.NonNull; import android.annotation.Nullable; -import android.os.Bundle; import android.platform.test.annotations.RavenwoodTestRunnerInitializing; import android.platform.test.annotations.internal.InnerRunner; import android.util.Log; -import androidx.test.platform.app.InstrumentationRegistry; - import com.android.ravenwood.common.RavenwoodCommonUtils; import org.junit.rules.TestRule; @@ -285,11 +282,6 @@ public final class RavenwoodAwareTestRunner extends RavenwoodAwareTestRunnerBase private boolean onBefore(Description description, Scope scope, Order order) { Log.v(TAG, "onBefore: description=" + description + ", " + scope + ", " + order); - if (scope == Scope.Instance && order == Order.Outer) { - // Start of a test method. - mState.enterTestMethod(description); - } - final var classDescription = getDescription(); // Class-level annotations are checked by the runner already, so we only check @@ -299,6 +291,12 @@ public final class RavenwoodAwareTestRunner extends RavenwoodAwareTestRunnerBase return false; } } + + if (scope == Scope.Instance && order == Order.Outer) { + // Start of a test method. + mState.enterTestMethod(description); + } + return true; } @@ -314,8 +312,7 @@ public final class RavenwoodAwareTestRunner extends RavenwoodAwareTestRunnerBase if (scope == Scope.Instance && order == Order.Outer) { // End of a test method. - mState.exitTestMethod(); - + mState.exitTestMethod(description); } // If RUN_DISABLED_TESTS is set, and the method did _not_ throw, make it an error. diff --git a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRunnerState.java b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRunnerState.java index 70bc52bdaa12..705186edba00 100644 --- a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRunnerState.java +++ b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRunnerState.java @@ -81,12 +81,15 @@ public final class RavenwoodRunnerState { RavenwoodRuntimeEnvironmentController.exitTestClass(); } + /** Called when a test method is about to start */ public void enterTestMethod(Description description) { mMethodDescription = description; - RavenwoodRuntimeEnvironmentController.initForMethod(); + RavenwoodRuntimeEnvironmentController.enterTestMethod(description); } - public void exitTestMethod() { + /** Called when a test method finishes */ + public void exitTestMethod(Description description) { + RavenwoodRuntimeEnvironmentController.exitTestMethod(description); mMethodDescription = null; } diff --git a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRuntimeEnvironmentController.java b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRuntimeEnvironmentController.java index f205d238c693..d935626c34df 100644 --- a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRuntimeEnvironmentController.java +++ b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRuntimeEnvironmentController.java @@ -51,6 +51,7 @@ import android.os.Build.VERSION_CODES; import android.os.Bundle; import android.os.HandlerThread; import android.os.Looper; +import android.os.Message; import android.os.Process_ravenwood; import android.os.ServiceManager; import android.os.ServiceManager.ServiceNotFoundException; @@ -74,6 +75,7 @@ import com.android.ravenwood.common.SneakyThrow; import com.android.server.LocalServices; import com.android.server.compat.PlatformCompat; +import org.junit.AssumptionViolatedException; import org.junit.internal.management.ManagementFactory; import org.junit.runner.Description; @@ -81,6 +83,7 @@ import java.io.File; import java.io.IOException; import java.io.PrintStream; import java.util.Collections; +import java.util.Comparator; import java.util.HashMap; import java.util.Locale; import java.util.Map; @@ -93,6 +96,7 @@ import java.util.concurrent.ScheduledFuture; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReference; import java.util.function.Supplier; +import java.util.stream.Collectors; /** * Responsible for initializing and the environment. @@ -107,32 +111,60 @@ public class RavenwoodRuntimeEnvironmentController { @SuppressWarnings("UnusedVariable") private static final PrintStream sStdErr = System.err; - private static final String MAIN_THREAD_NAME = "RavenwoodMain"; + private static final String MAIN_THREAD_NAME = "Ravenwood:Main"; + private static final String TESTS_THREAD_NAME = "Ravenwood:Test"; + private static final String LIBRAVENWOOD_INITIALIZER_NAME = "ravenwood_initializer"; private static final String RAVENWOOD_NATIVE_RUNTIME_NAME = "ravenwood_runtime"; private static final String ANDROID_LOG_TAGS = "ANDROID_LOG_TAGS"; private static final String RAVENWOOD_ANDROID_LOG_TAGS = "RAVENWOOD_" + ANDROID_LOG_TAGS; + static volatile Thread sTestThread; + static volatile Thread sMainThread; + /** * 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 = - "1".equals(System.getenv("RAVENWOOD_ENABLE_TIMEOUT_STACKS")); + !"0".equals(System.getenv("RAVENWOOD_ENABLE_TIMEOUT_STACKS")); + + private static final boolean TOLERATE_LOOPER_ASSERTS = + !"0".equals(System.getenv("RAVENWOOD_TOLERATE_LOOPER_ASSERTS")); + + static final int DEFAULT_TIMEOUT_SECONDS = 10; + private static final int TIMEOUT_MILLIS = getTimeoutSeconds() * 1000; + + 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 int TIMEOUT_MILLIS = 9_000; private static final ScheduledExecutorService sTimeoutExecutor = - Executors.newScheduledThreadPool(1); + Executors.newScheduledThreadPool(1, (Runnable r) -> { + Thread t = Executors.defaultThreadFactory().newThread(r); + t.setName("Ravenwood:TimeoutMonitor"); + t.setDaemon(true); + return t; + }); - private static ScheduledFuture sPendingTimeout; + private static volatile ScheduledFuture sPendingTimeout; /** * When enabled, attempt to detect uncaught exceptions from background threads. */ private static final boolean ENABLE_UNCAUGHT_EXCEPTION_DETECTION = - "1".equals(System.getenv("RAVENWOOD_ENABLE_UNCAUGHT_EXCEPTION_DETECTION")); + !"0".equals(System.getenv("RAVENWOOD_ENABLE_UNCAUGHT_EXCEPTION_DETECTION")); + + private static final boolean DIE_ON_UNCAUGHT_EXCEPTION = true; /** * When set, an unhandled exception was discovered (typically on a background thread), and we @@ -141,12 +173,6 @@ public class RavenwoodRuntimeEnvironmentController { private static final AtomicReference sPendingUncaughtException = new AtomicReference<>(); - private static final Thread.UncaughtExceptionHandler sUncaughtExceptionHandler = - (thread, throwable) -> { - // Remember the first exception we discover - sPendingUncaughtException.compareAndSet(null, throwable); - }; - // TODO: expose packCallingIdentity function in libbinder and use it directly // See: packCallingIdentity in frameworks/native/libs/binder/IPCThreadState.cpp private static long packBinderIdentityToken( @@ -187,6 +213,8 @@ public class RavenwoodRuntimeEnvironmentController { * Initialize the global environment. */ public static void globalInitOnce() { + sTestThread = Thread.currentThread(); + Thread.currentThread().setName(TESTS_THREAD_NAME); synchronized (sInitializationLock) { if (!sInitialized) { // globalInitOnce() is called from class initializer, which cause @@ -194,6 +222,7 @@ public class RavenwoodRuntimeEnvironmentController { sInitialized = true; // This is the first call. + final long start = System.currentTimeMillis(); try { globalInitInner(); } catch (Throwable th) { @@ -202,6 +231,9 @@ public class RavenwoodRuntimeEnvironmentController { sExceptionFromGlobalInit = th; SneakyThrow.sneakyThrow(th); } + final long end = System.currentTimeMillis(); + // TODO Show user/system time too + Log.e(TAG, "globalInit() took " + (end - start) + "ms"); } else { // Subsequent calls. If the first call threw, just throw the same error, to prevent // the test from running. @@ -220,7 +252,8 @@ public class RavenwoodRuntimeEnvironmentController { RavenwoodCommonUtils.log(TAG, "globalInitInner()"); if (ENABLE_UNCAUGHT_EXCEPTION_DETECTION) { - Thread.setDefaultUncaughtExceptionHandler(sUncaughtExceptionHandler); + Thread.setDefaultUncaughtExceptionHandler( + RavenwoodRuntimeEnvironmentController::reportUncaughtExceptions); } // Some process-wide initialization: @@ -304,6 +337,7 @@ public class RavenwoodRuntimeEnvironmentController { ActivityManager.init$ravenwood(SYSTEM.getIdentifier()); final var main = new HandlerThread(MAIN_THREAD_NAME); + sMainThread = main; main.start(); Looper.setMainLooperForTest(main.getLooper()); @@ -350,9 +384,20 @@ public class RavenwoodRuntimeEnvironmentController { var systemServerContext = new RavenwoodContext(ANDROID_PACKAGE_NAME, main, systemResourcesLoader); - sInstrumentation = new Instrumentation(); - sInstrumentation.basicInit(instContext, targetContext, null); - InstrumentationRegistry.registerInstance(sInstrumentation, Bundle.EMPTY); + var instArgs = Bundle.EMPTY; + RavenwoodUtils.runOnMainThreadSync(() -> { + try { + // TODO We should get the instrumentation class name from the build file or + // somewhere. + var InstClass = Class.forName("android.app.Instrumentation"); + sInstrumentation = (Instrumentation) InstClass.getConstructor().newInstance(); + sInstrumentation.basicInit(instContext, targetContext, null); + sInstrumentation.onCreate(instArgs); + } catch (Exception e) { + SneakyThrow.sneakyThrow(e); + } + }); + InstrumentationRegistry.registerInstance(sInstrumentation, instArgs); RavenwoodSystemServer.init(systemServerContext); @@ -399,22 +444,46 @@ public class RavenwoodRuntimeEnvironmentController { SystemProperties.clearChangeCallbacksForTest(); - if (ENABLE_TIMEOUT_STACKS) { - sPendingTimeout = sTimeoutExecutor.schedule( - RavenwoodRuntimeEnvironmentController::dumpStacks, - TIMEOUT_MILLIS, TimeUnit.MILLISECONDS); - } - if (ENABLE_UNCAUGHT_EXCEPTION_DETECTION) { - maybeThrowPendingUncaughtException(false); - } + maybeThrowPendingUncaughtException(); } /** - * Partially reset and initialize before each test method invocation + * Called when a test method is about to be started. */ - public static void initForMethod() { + public static void enterTestMethod(Description description) { // TODO(b/375272444): this is a hacky workaround to ensure binder identity Binder.restoreCallingIdentity(sCallingIdentity); + + scheduleTimeout(); + } + + /** + * Called when a test method finished. + */ + public static void exitTestMethod(Description description) { + cancelTimeout(); + maybeThrowPendingUncaughtException(); + } + + private static void scheduleTimeout() { + if (!ENABLE_TIMEOUT_STACKS) { + return; + } + cancelTimeout(); + + sPendingTimeout = sTimeoutExecutor.schedule( + RavenwoodRuntimeEnvironmentController::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() { @@ -472,16 +541,37 @@ public class RavenwoodRuntimeEnvironmentController { return ret; } + /** + * Return if an exception is benign and okay to continue running the main looper even + * if we detect it. + */ + private static boolean isThrowableBenign(Throwable th) { + return th instanceof AssertionError || th instanceof AssumptionViolatedException; + } + + static void dispatchMessage(Message msg) { + try { + msg.getTarget().dispatchMessage(msg); + } catch (Throwable th) { + var desc = String.format("Detected %s on looper thread %s", th.getClass().getName(), + Thread.currentThread()); + sStdErr.println(desc); + if (TOLERATE_LOOPER_ASSERTS && isThrowableBenign(th)) { + sStdErr.printf("*** Continuing the test because it's %s ***\n", + th.getClass().getSimpleName()); + var e = new Exception(desc, th); + sPendingUncaughtException.compareAndSet(null, e); + return; + } + throw th; + } + } + /** * A callback when a test class finishes its execution, mostly only for debugging. */ public static void exitTestClass() { - if (ENABLE_TIMEOUT_STACKS) { - sPendingTimeout.cancel(false); - } - if (ENABLE_UNCAUGHT_EXCEPTION_DETECTION) { - maybeThrowPendingUncaughtException(true); - } + maybeThrowPendingUncaughtException(); } public static void logTestRunner(String label, Description description) { @@ -491,35 +581,70 @@ public class RavenwoodRuntimeEnvironmentController { + "(" + description.getTestClass().getName() + ")"); } - private static void dumpStacks() { - final PrintStream out = System.err; - out.println("-----BEGIN ALL THREAD STACKS-----"); - final Map stacks = Thread.getAllStackTraces(); - for (Map.Entry stack : stacks.entrySet()) { - out.println(); - Thread t = stack.getKey(); - out.println(t.toString() + " ID=" + t.getId()); - for (StackTraceElement e : stack.getValue()) { - out.println("\tat " + e); - } + private static void maybeThrowPendingUncaughtException() { + final Throwable pending = sPendingUncaughtException.getAndSet(null); + if (pending != null) { + throw new IllegalStateException("Found an uncaught exception", pending); } - out.println("-----END ALL THREAD STACKS-----"); } /** - * If there's a pending uncaught exception, consume and throw it now. Typically used to - * report an exception on a background thread as a failure for the currently running test. + * Prints the stack trace from all threads. */ - private static void maybeThrowPendingUncaughtException(boolean duringReset) { - final Throwable pending = sPendingUncaughtException.getAndSet(null); - if (pending != null) { - if (duringReset) { - throw new IllegalStateException( - "Found an uncaught exception during this test", pending); - } else { - throw new IllegalStateException( - "Found an uncaught exception before this test started", pending); + private static void onTestTimedOut() { + sStdErr.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 = sStdErr; + 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 testThread = sTestThread; + var mainThread = sMainThread; + 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-----"); } } @@ -545,13 +670,17 @@ public class RavenwoodRuntimeEnvironmentController { () -> Class.forName("org.mockito.Matchers")); } - // TODO: use the real UiAutomation class instead of a mock - private static UiAutomation createMockUiAutomation() { - sAdoptedPermissions = Collections.emptySet(); - var mock = mock(UiAutomation.class, inv -> { + static T makeDefaultThrowMock(Class clazz) { + return mock(clazz, inv -> { HostTestUtils.onThrowMethodCalled(); return null; }); + } + + // TODO: use the real UiAutomation class instead of a mock + private static UiAutomation createMockUiAutomation() { + sAdoptedPermissions = Collections.emptySet(); + var mock = makeDefaultThrowMock(UiAutomation.class); doAnswer(inv -> { sAdoptedPermissions = UiAutomation.ALL_PERMISSIONS; return null; @@ -586,6 +715,23 @@ public class RavenwoodRuntimeEnvironmentController { } } + private static void reportUncaughtExceptions(Thread th, Throwable e) { + sStdErr.printf("Uncaught exception detected: %s: %s\n", + th, RavenwoodCommonUtils.getStackTraceString(e)); + + doBugreport(th, e, DIE_ON_UNCAUGHT_EXCEPTION); + } + + private 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.v(TAG, "JVM properties:"); dumpMap(System.getProperties()); @@ -601,7 +747,6 @@ public class RavenwoodRuntimeEnvironmentController { Log.v(TAG, " " + key + "=" + map.get(key)); } } - private static void dumpOtherInfo() { Log.v(TAG, "Other key information:"); var jloc = Locale.getDefault(); diff --git a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodSystemProperties.java b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodSystemProperties.java index 70c161c1f19a..819d93a9c336 100644 --- a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodSystemProperties.java +++ b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodSystemProperties.java @@ -26,6 +26,7 @@ import java.io.IOException; import java.nio.file.Files; import java.nio.file.Path; import java.util.HashMap; +import java.util.HashSet; import java.util.LinkedHashMap; import java.util.Map; import java.util.Set; @@ -45,6 +46,9 @@ public class RavenwoodSystemProperties { /** The default values. */ static final Map sDefaultValues = new HashMap<>(); + static final Set sReadableKeys = new HashSet<>(); + static final Set sWritableKeys = new HashSet<>(); + private static final String[] PARTITIONS = { "bootimage", "odm", @@ -88,9 +92,24 @@ public class RavenwoodSystemProperties { ravenwoodProps.forEach((key, origValue) -> { final String value; - // If a value starts with "$$$", then this is a reference to the device-side value. if (origValue.startsWith("$$$")) { + // If a value starts with "$$$", then: + // - If it's "$$$r", the key is allowed to read. + // - If it's "$$$w", the key is allowed to write. + // - Otherwise, it's a reference to the device-side value. + // In case of $$$r and $$$w, if the key ends with a '.', then it'll be treaded + // as a prefix match. var deviceKey = origValue.substring(3); + if ("r".equals(deviceKey)) { + sReadableKeys.add(key); + Log.v(TAG, key + " (readable)"); + return; + } else if ("w".equals(deviceKey)) { + sWritableKeys.add(key); + Log.v(TAG, key + " (writable)"); + return; + } + var deviceValue = deviceProps.get(deviceKey); if (deviceValue == null) { throw new RuntimeException("Failed to initialize system properties. Key '" @@ -131,50 +150,38 @@ public class RavenwoodSystemProperties { sDefaultValues.forEach(RavenwoodRuntimeNative::setSystemProperty); } - private static boolean isKeyReadable(String key) { - // All writable keys are also readable - if (isKeyWritable(key)) return true; + private static boolean checkAllowedInner(String key, Set allowed) { + if (allowed.contains(key)) { + return true; + } - final String root = getKeyRoot(key); + // Also search for a prefix match. + for (var k : allowed) { + if (k.endsWith(".") && key.startsWith(k)) { + return true; + } + } + return false; + } - // This set is carefully curated to help identify situations where a test may - // accidentally depend on a default value of an obscure property whose owner hasn't - // decided how Ravenwood should behave. - if (root.startsWith("boot.")) return true; - if (root.startsWith("build.")) return true; - if (root.startsWith("product.")) return true; - if (root.startsWith("soc.")) return true; - if (root.startsWith("system.")) return true; + private static boolean checkAllowed(String key, Set allowed) { + return checkAllowedInner(key, allowed) || checkAllowedInner(getKeyRoot(key), allowed); + } + private static boolean isKeyReadable(String key) { // All core values should be readable - if (sDefaultValues.containsKey(key)) return true; - - // Hardcoded allowlist - return switch (key) { - case "gsm.version.baseband", - "no.such.thing", - "qemu.sf.lcd_density", - "ro.bootloader", - "ro.hardware", - "ro.hw_timeout_multiplier", - "ro.odm.build.media_performance_class", - "ro.sf.lcd_density", - "ro.treble.enabled", - "ro.vndk.version", - "ro.icu.data.path" -> true; - default -> false; - }; + if (sDefaultValues.containsKey(key)) { + return true; + } + if (checkAllowed(key, sReadableKeys)) { + return true; + } + // All writable keys are also readable + return isKeyWritable(key); } private static boolean isKeyWritable(String key) { - final String root = getKeyRoot(key); - - if (root.startsWith("debug.")) return true; - - // For PropertyInvalidatedCache - if (root.startsWith("cache_key.")) return true; - - return false; + return checkAllowed(key, sWritableKeys); } static boolean isKeyAccessible(String key, boolean write) { -- cgit v1.2.3-59-g8ed1b