Add a better "method call" (optional) log (5cbf9fd1) · Commits · e / os / android_frameworks_base

ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodMethodCallLogger.java

0 → 100644

+229 −0

Original line number	Diff line number	Diff line
		/*
		* Copyright (C) 2025 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.platform.test.ravenwood;

		import com.android.ravenwood.RavenwoodRuntimeNative;

		import java.io.PrintStream;
		import java.util.HashSet;
		import java.util.Objects;

		/**
		* Provides a method call hook that prints almost all (see below) the framework methods being
		* called with indentation.
		*
		* We don't log methods that are trivial, uninteresting, or would be too noisy.
		* e.g. we don't want to log any logging related methods, or collection APIs.
		*
		*/
		public class RavenwoodMethodCallLogger {
		private RavenwoodMethodCallLogger() {
		}

		/** We don't want to log anything before ravenwood is initialized. This flag controls it.*/
		private static volatile boolean sEnabled = false;

		private static volatile PrintStream sOut = System.out;

		/** Return the current thread's call nest level. */
		private static int getNestLevel() {
		return Thread.currentThread().getStackTrace().length;
		}

		private static class ThreadInfo {
		/**
		* We save the current thread's nest call level here and use that as the initial level.
		* We do it because otherwise the nest level would be too deep by the time test
		* starts.
		*/
		public final int mInitialNestLevel = getNestLevel();

		/**
		* A nest level where shouldLog() returned false.
		* Once it's set, we ignore all calls deeper than this.
		*/
		public int mDisabledNestLevel = Integer.MAX_VALUE;
		}

		private static final ThreadLocal<ThreadInfo> sThreadInfo = new ThreadLocal<>() {
		@Override
		protected ThreadInfo initialValue() {
		return new ThreadInfo();
		}
		};

		/** Classes that should be logged. Uses a map for fast lookup. */
		private static final HashSet<Class> sIgnoreClasses = new HashSet<>();
		static {
		// The following classes are not interesting...
		sIgnoreClasses.add(android.util.Log.class);
		sIgnoreClasses.add(android.util.Slog.class);
		sIgnoreClasses.add(android.util.EventLog.class);
		sIgnoreClasses.add(android.util.TimingsTraceLog.class);

		sIgnoreClasses.add(android.util.SparseArray.class);
		sIgnoreClasses.add(android.util.SparseIntArray.class);
		sIgnoreClasses.add(android.util.SparseLongArray.class);
		sIgnoreClasses.add(android.util.SparseBooleanArray.class);
		sIgnoreClasses.add(android.util.SparseDoubleArray.class);
		sIgnoreClasses.add(android.util.SparseSetArray.class);
		sIgnoreClasses.add(android.util.SparseArrayMap.class);
		sIgnoreClasses.add(android.util.LongSparseArray.class);
		sIgnoreClasses.add(android.util.LongSparseLongArray.class);
		sIgnoreClasses.add(android.util.LongArray.class);

		sIgnoreClasses.add(android.text.FontConfig.class);

		sIgnoreClasses.add(android.os.SystemClock.class);
		sIgnoreClasses.add(android.os.Trace.class);
		sIgnoreClasses.add(android.os.LocaleList.class);
		sIgnoreClasses.add(android.os.Build.class);
		sIgnoreClasses.add(android.os.SystemProperties.class);

		sIgnoreClasses.add(com.android.internal.util.Preconditions.class);

		sIgnoreClasses.add(android.graphics.FontListParser.class);
		sIgnoreClasses.add(android.graphics.ColorSpace.class);

		sIgnoreClasses.add(android.graphics.fonts.FontStyle.class);
		sIgnoreClasses.add(android.graphics.fonts.FontVariationAxis.class);

		sIgnoreClasses.add(com.android.internal.compat.CompatibilityChangeInfo.class);
		sIgnoreClasses.add(com.android.internal.os.LoggingPrintStream.class);

		sIgnoreClasses.add(android.os.ThreadLocalWorkSource.class);

		// Following classes may be interesting for some purposes, but the initialization is
		// too noisy...
		sIgnoreClasses.add(android.graphics.fonts.SystemFonts.class);

		}

		/**
		* Return if a class should be ignored. Uses {link #sIgnoreCladsses}, but
		* we ignore more classes.
		*/
		private static boolean shouldIgnoreClass(Class<?> clazz) {
		if (sIgnoreClasses.contains(clazz)) {
		return true;
		}
		// Let's also ignore collection-ish classes in android.util.
		if (java.util.Collection.class.isAssignableFrom(clazz)
		\|\| java.util.Map.class.isAssignableFrom(clazz)
		) {
		if ("android.util".equals(clazz.getPackageName())) {
		return true;
		}
		return false;
		}

		switch (clazz.getSimpleName()) {
		case "EventLogTags":
		return false;
		}

		// Following are classes that can't be referred to here directly.
		// e.g. AndroidPrintStream is package-private, so we can't use its "class" here.
		switch (clazz.getName()) {
		case "com.android.internal.os.AndroidPrintStream":
		return false;
		}
		return false;
		}

		private static boolean shouldLog(
		Class<?> methodClass,
		String methodName,
		@SuppressWarnings("UnusedVariable") String methodDescriptor
		) {
		// Should we ignore this class?
		if (shouldIgnoreClass(methodClass)) {
		return false;
		}
		// Is it a nested class in a class that should be ignored?
		var host = methodClass.getNestHost();
		if (host != methodClass && shouldIgnoreClass(host)) {
		return false;
		}

		var className = methodClass.getName();

		// Ad-hoc ignore list. They'd be too noisy.
		if ("create".equals(methodName)
		// We may apply jarjar, so use endsWith().
		&& className.endsWith("com.android.server.compat.CompatConfig")) {
		return false;
		}

		var pkg = methodClass.getPackageName();
		if (pkg.startsWith("android.icu")) {
		return false;
		}

		return true;
		}

		/**
		* Call this to enable logging.
		*/
		public static void enable(PrintStream out) {
		sEnabled = true;
		sOut = Objects.requireNonNull(out);

		// It's called from the test thread (Java's main thread). Because we're already
		// in deep nest calls, we initialize the initial nest level here.
		sThreadInfo.get();
		}

		/** Actual method hook entry point.*/
		public static void logMethodCall(
		Class<?> methodClass,
		String methodName,
		String methodDescriptor
		) {
		if (!sEnabled) {
		return;
		}
		final var ti = sThreadInfo.get();
		final int nestLevel = getNestLevel() - ti.mInitialNestLevel;

		// Once shouldLog() returns false, we just ignore all deeper calls.
		if (ti.mDisabledNestLevel < nestLevel) {
		return; // Still ignore.
		}
		final boolean shouldLog = shouldLog(methodClass, methodName, methodDescriptor);

		if (!shouldLog) {
		ti.mDisabledNestLevel = nestLevel;
		return;
		}
		ti.mDisabledNestLevel = Integer.MAX_VALUE;

		var out = sOut;
		out.print("# [");
		out.print(RavenwoodRuntimeNative.gettid());
		out.print(": ");
		out.print(Thread.currentThread().getName());
		out.print("]: ");
		out.print("[@");
		out.printf("%2d", nestLevel);
		out.print("] ");
		for (int i = 0; i < nestLevel; i++) {
		out.print(" ");
		}
		out.println(methodClass.getName() + "." + methodName + methodDescriptor);
		}
		}

ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRuntimeEnvironmentController.java

+10 −7

Original line number	Diff line number	Diff line
		@@ -23,7 +23,6 @@ import static android.platform.test.ravenwood.RavenwoodSystemServer.ANDROID_PACK
		import static com.android.ravenwood.common.RavenwoodCommonUtils.RAVENWOOD_EMPTY_RESOURCES_APK;
		import static com.android.ravenwood.common.RavenwoodCommonUtils.RAVENWOOD_INST_RESOURCE_APK;
		import static com.android.ravenwood.common.RavenwoodCommonUtils.RAVENWOOD_RESOURCE_APK;
		import static com.android.ravenwood.common.RavenwoodCommonUtils.RAVENWOOD_VERBOSE_LOGGING;
		import static com.android.ravenwood.common.RavenwoodCommonUtils.RAVENWOOD_VERSION_JAVA_SYSPROP;
		import static com.android.ravenwood.common.RavenwoodCommonUtils.parseNullableInt;
		import static com.android.ravenwood.common.RavenwoodCommonUtils.withDefault;
		@@ -103,6 +102,10 @@ public class RavenwoodRuntimeEnvironmentController {
		private RavenwoodRuntimeEnvironmentController() {
		}

		private static final PrintStream sStdOut = System.out;
		@SuppressWarnings("UnusedVariable")
		private static final PrintStream sStdErr = System.err;

		private static final String MAIN_THREAD_NAME = "RavenwoodMain";
		private static final String LIBRAVENWOOD_INITIALIZER_NAME = "ravenwood_initializer";
		private static final String RAVENWOOD_NATIVE_RUNTIME_NAME = "ravenwood_runtime";
		@@ -212,9 +215,9 @@ public class RavenwoodRuntimeEnvironmentController {
		}

		private static void globalInitInner() throws IOException {
		if (RAVENWOOD_VERBOSE_LOGGING) {
		Log.v(TAG, "globalInit() called here...", new RuntimeException("NOT A CRASH"));
		}
		// We haven't initialized liblog yet, so directly write to System.out here.
		RavenwoodCommonUtils.log(TAG, "globalInitInner()");

		if (ENABLE_UNCAUGHT_EXCEPTION_DETECTION) {
		Thread.setDefaultUncaughtExceptionHandler(sUncaughtExceptionHandler);
		}
		@@ -234,9 +237,6 @@ public class RavenwoodRuntimeEnvironmentController {
		dumpJavaProperties();
		dumpOtherInfo();

		// We haven't initialized liblog yet, so directly write to System.out here.
		RavenwoodCommonUtils.log(TAG, "globalInitInner()");

		// Make sure libravenwood_runtime is loaded.
		System.load(RavenwoodCommonUtils.getJniLibraryPath(RAVENWOOD_NATIVE_RUNTIME_NAME));

		@@ -261,6 +261,9 @@ public class RavenwoodRuntimeEnvironmentController {
		// Make sure libandroid_runtime is loaded.
		RavenwoodNativeLoader.loadFrameworkNativeCode();

		// Start method logging.
		RavenwoodMethodCallLogger.enable(sStdOut);

		// Touch some references early to ensure they're <clinit>'ed
		Objects.requireNonNull(Build.TYPE);
		Objects.requireNonNull(Build.VERSION.SDK);

ravenwood/texts/ravenwood-standard-options.txt

+3 −1

Original line number	Diff line number	Diff line
		@@ -9,8 +9,10 @@

		# Uncomment below lines to enable each feature.

		# Enable method call hook.
		#--default-method-call-hook
		# com.android.hoststubgen.hosthelper.HostTestUtils.logMethodCall
		# android.platform.test.ravenwood.RavenwoodMethodCallLogger.logMethodCall

		#--default-class-load-hook
		# com.android.hoststubgen.hosthelper.HostTestUtils.logClassLoaded

ravenwood/tools/hoststubgen/helper-runtime-src/com/android/hoststubgen/hosthelper/HostTestUtils.java

+28 −15

Original line number	Diff line number	Diff line
		@@ -18,6 +18,7 @@ package com.android.hoststubgen.hosthelper;
		import java.io.PrintStream;
		import java.lang.reflect.Method;
		import java.lang.reflect.Modifier;
		import java.util.Arrays;

		/**
		* Utilities used in the host side test environment.
		@@ -36,9 +37,14 @@ public class HostTestUtils {

		public static final String CLASS_INTERNAL_NAME = getInternalName(HostTestUtils.class);

		/** If true, we skip all method call hooks */
		private static final boolean SKIP_METHOD_CALL_HOOK = "1".equals(System.getenv(
		"HOSTTEST_SKIP_METHOD_CALL_HOOK"));

		/** If true, we won't print method call log. */
		private static final boolean SKIP_METHOD_LOG = "1".equals(System.getenv(
		"HOSTTEST_SKIP_METHOD_LOG"));
		private static final boolean SKIP_METHOD_LOG =
		"1".equals(System.getenv("HOSTTEST_SKIP_METHOD_LOG"))
		\|\| "1".equals(System.getenv("RAVENWOOD_NO_METHOD_LOG"));

		/** If true, we won't print class load log. */
		private static final boolean SKIP_CLASS_LOG = "1".equals(System.getenv(
		@@ -65,6 +71,9 @@ public class HostTestUtils {
		+ "consider using Mockito; more details at go/ravenwood-docs");
		}

		private static final Class<?>[] sMethodHookArgTypes =
		{ Class.class, String.class, String.class};

		/**
		* Trampoline method for method-call-hook.
		*/
		@@ -74,16 +83,22 @@ public class HostTestUtils {
		String methodDescriptor,
		String callbackMethod
		) {
		callStaticMethodByName(callbackMethod, "method call hook", methodClass,
		methodName, methodDescriptor);
		if (SKIP_METHOD_CALL_HOOK) {
		return;
		}
		callStaticMethodByName(callbackMethod, "method call hook", sMethodHookArgTypes,
		methodClass, methodName, methodDescriptor);
		}

		/**
		* Simple implementation of method call hook, which just prints the information of the
		* method. This is just for basic testing. We don't use it in Ravenwood, because this would
		* be way too noisy as it prints every single method, even trivial ones. (iterator methods,
		* etc..)
		*
		* I can be used as
		* {@code --default-method-call-hook
		* com.android.hoststubgen.hosthelper.HostTestUtils.logMethodCall}.
		*
		* It logs every single methods called.
		*/
		public static void logMethodCall(
		Class<?> methodClass,
		@@ -97,6 +112,8 @@ public class HostTestUtils {
		+ methodName + methodDescriptor);
		}

		private static final Class<?>[] sClassLoadHookArgTypes = { Class.class };

		/**
		* Called when any top level class (not nested classes) in the impl jar is loaded.
		*
		@@ -111,11 +128,12 @@ public class HostTestUtils {
		logPrintStream.println("! Class loaded: " + loadedClass.getCanonicalName()
		+ " calling hook " + callbackMethod);

		callStaticMethodByName(callbackMethod, "class load hook", loadedClass);
		callStaticMethodByName(
		callbackMethod, "class load hook", sClassLoadHookArgTypes, loadedClass);
		}

		private static void callStaticMethodByName(String classAndMethodName,
		String description, Object... args) {
		String description, Class<?>[] argTypes, Object... args) {
		// Forward the call to callbackMethod.
		final int lastPeriod = classAndMethodName.lastIndexOf(".");

		@@ -145,19 +163,14 @@ public class HostTestUtils {
		className));
		}

		Class<?>[] argTypes = new Class[args.length];
		for (int i = 0; i < args.length; i++) {
		argTypes[i] = args[i].getClass();
		}

		Method method = null;
		try {
		method = clazz.getMethod(methodName, argTypes);
		} catch (Exception e) {
		throw new HostTestException(String.format(
		"Unable to find %s: class %s doesn't have method %s"
		+ " (method must take exactly one parameter of type Class,"
		+ " and public static)",
		+ " Method must be public static, and arg types must be: "
		+ Arrays.toString(argTypes),
		description, className, methodName), e);
		}
		if (!(Modifier.isPublic(method.getModifiers())

ravenwood/tools/hoststubgen/src/com/android/hoststubgen/HostStubGen.kt

+1 −0

Original line number	Diff line number	Diff line
		@@ -145,6 +145,7 @@ class HostStubGen(val options: HostStubGenOptions) {

		// Inject default hooks from options.
		filter = DefaultHookInjectingFilter(
		allClasses,
		options.defaultClassLoadHook.get,
		options.defaultMethodCallHook.get,
		filter