RavenwoodMethodCallLogger now supports creating a policy file. (0dd83cea) · Commits · e / os / android_frameworks_base

ravenwood/Android.bp

+5 −0

Original line number	Diff line number	Diff line
		@@ -132,6 +132,11 @@ java_library {
		"ravenwood-androidx",
		"ravenwood-common-utils",
		"ravenwood-libcore",
		"ow2-asm",
		"ow2-asm-analysis",
		"ow2-asm-commons",
		"ow2-asm-tree",
		"ow2-asm-util",
		],
		libs: [
		"framework-configinfrastructure.ravenwood",

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

0 → 100644

+109 −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 android.annotation.NonNull;
		import android.annotation.Nullable;
		import android.util.Log;

		import org.objectweb.asm.Type;

		import java.lang.reflect.Executable;

		/**
		* Utility methods related to ASM.
		*/
		public class RavenwoodAsmUtils {
		private static final String TAG = "RavenwoodAsmUtils";

		private RavenwoodAsmUtils() {
		}

		/**
		* Converts an ASM Type to a Java Class.
		*/
		@NonNull
		public static Class<?> toClass(@NonNull Type type)
		throws ClassNotFoundException {
		var cl = RavenwoodAsmUtils.class.getClassLoader();
		return switch (type.getSort()) {
		case Type.VOID -> void.class;
		case Type.BOOLEAN -> boolean.class;
		case Type.CHAR -> char.class;
		case Type.BYTE -> byte.class;
		case Type.SHORT -> short.class;
		case Type.INT -> int.class;
		case Type.FLOAT -> float.class;
		case Type.LONG -> long.class;
		case Type.DOUBLE -> double.class;
		case Type.ARRAY -> Class.forName(type.getDescriptor().replace('/', '.'),
		false, cl);
		case Type.OBJECT -> Class.forName(type.getClassName(), false, cl);
		default -> throw new ClassNotFoundException("Unsupported ASM Type: " + type);
		};
		}

		/**
		* Finds a Method or a Constructor object using its class, name, and ASM-style descriptor.
		*
		* Note, the static initializer ("<clinit>") can't be accessed via reflections. It'd cause
		* {@link NoSuchMethodException}.
		*/
		@NonNull
		private static Executable getMethod(
		@NonNull Class<?> clazz,
		@NonNull String methodName,
		@NonNull String methodDesc)
		throws ClassNotFoundException, NoSuchMethodException {

		// 1. Use ASM to parse the method descriptor
		Type[] asmParamTypes = Type.getArgumentTypes(methodDesc);
		Class<?>[] javaParamTypes = new Class<?>[asmParamTypes.length];

		// 2. Convert ASM Type objects to Java Class objects
		for (int i = 0; i < asmParamTypes.length; i++) {
		javaParamTypes[i] = toClass(asmParamTypes[i]);
		}

		// 3. Use standard Java Reflection to find the method
		if (methodName.equals("<init>")) {
		return clazz.getDeclaredConstructor(javaParamTypes);
		} else {
		return clazz.getDeclaredMethod(methodName, javaParamTypes);
		}
		}

		/**
		* Same as {@link #getMethod} but it'll return null for errors instead of exceptions.
		*/
		@Nullable
		public static Executable getMethodOrNull(
		@NonNull Class<?> clazz,
		@NonNull String methodName,
		@NonNull String methodDesc) {
		if (methodName.equals("<clinit>")) {
		return null; // static initializer can't be resolved.
		}
		try {
		return getMethod(clazz, methodName, methodDesc);
		} catch (Exception e) {
		Log.w(TAG, String.format(
		"Method not found: class=%s name=%s desc=%s",
		clazz, methodName, methodDesc));
		return null;
		}
		}
		}

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

+1 −1

Original line number	Diff line number	Diff line
		@@ -260,7 +260,7 @@ public class RavenwoodDriver {
		RavenwoodNativeLoader.loadFrameworkNativeCode();

		// Start method logging.
		RavenwoodMethodCallLogger.enable(sRawStdOut);
		RavenwoodMethodCallLogger.getInstance().enable(sRawStdOut);

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

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

+308 −44

Original line number	Diff line number	Diff line
		@@ -15,35 +15,144 @@
		*/
		package android.platform.test.ravenwood;

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

		import com.android.hoststubgen.hosthelper.HostTestUtils;
		import com.android.internal.annotations.GuardedBy;
		import com.android.internal.annotations.VisibleForTesting;
		import com.android.ravenwood.RavenwoodRuntimeNative;
		import com.android.ravenwood.common.SneakyThrow;

		import java.io.BufferedOutputStream;
		import java.io.FileNotFoundException;
		import java.io.FileOutputStream;
		import java.io.OutputStream;
		import java.io.PrintStream;
		import java.io.PrintWriter;
		import java.util.Comparator;
		import java.util.HashMap;
		import java.util.HashSet;
		import java.util.Map;
		import java.util.Objects;
		import java.util.Set;
		import java.util.function.Predicate;
		import java.util.function.Supplier;
		import java.util.regex.Pattern;

		/**
		* Provides a method call hook that prints almost all (see below) the framework methods being
		* called with indentation.
		*
		* Enable this method call logging by adding the following lines to the options file.
		* (frameworks/base/ravenwood/texts/ravenwood-standard-options.txt)

		--default-method-call-hook
		android.platform.test.ravenwood.RavenwoodMethodCallLogger.logMethodCall

		*
		* 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.
		* e.g. we don't want to log any logging related methods or collection APIs.
		*
		* This class also dumps all the called method names in the
		* {@link #CALLED_METHOD_POLICY_FILE} file in the form of a policy file.
		* Optionally, if $RAVENWOOD_METHOD_DUMP_REASON_FILTER is defined, the method policy dump
		* will only contain methods with filter reasons matching it as a regex.
		*/
		public class RavenwoodMethodCallLogger {
		private RavenwoodMethodCallLogger() {
		private static final String TAG = "RavenwoodMethodCallLogger";

		private static final boolean LOG_ALL_METHODS = "1".equals(
		System.getenv("RAVENWOOD_METHOD_LOG_NO_FILTER"));

		/** The policy file is created with this filename. */
		private static final String CALLED_METHOD_POLICY_FILE = "/tmp/ravenwood-called-methods.txt";

		/**
		* If set, we filter methods by applying this regex on the HostStubGen "filter reason"
		* when generating the policy file.
		*/
		private static final String CALLED_METHOD_DUMP_REASON_FILTER_RE = System.getenv(
		"RAVENWOOD_METHOD_DUMP_REASON_FILTER");

		/** It's a singleton, except we create different instances for unit tests. */
		@VisibleForTesting
		public RavenwoodMethodCallLogger(boolean logAllMethods) {
		mLogAllMethods = logAllMethods;
		}

		/** Singleton instance */
		private static final RavenwoodMethodCallLogger sInstance =
		new RavenwoodMethodCallLogger(LOG_ALL_METHODS);

		/**
		* @return the singleton instance.
		*/
		public static RavenwoodMethodCallLogger getInstance() {
		return sInstance;
		}

		/** Entry point for HostStubGen generated code, which needs to be static.*/
		public static void logMethodCall(
		Class<?> methodClass,
		String methodName,
		String methodDesc
		) {
		getInstance().onMethodCalled(methodClass, methodName, methodDesc);
		}


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

		private static volatile PrintStream sOut = System.out;
		private volatile PrintStream mOut = System.out;

		private final boolean mLogAllMethods;

		private static class MethodDesc {
		public final String name;
		public final String desc;
		private String mReason;

		public MethodDesc(String name, String desc) {
		this.name = name;
		this.desc = desc;
		}

		public void setReason(String reason) {
		mReason = reason;
		}

		public String getReason() {
		return mReason;
		}

		@Override
		public boolean equals(Object o) {
		if (!(o instanceof MethodDesc that)) return false;
		return Objects.equals(name, that.name) && Objects.equals(desc, that.desc);
		}

		@Override
		public int hashCode() {
		return Objects.hash(name, desc);
		}
		}

		/** Stores all called methods. */
		@GuardedBy("sAllMethods")
		private final Map<Class<?>, Set<MethodDesc>> mAllMethods = new HashMap<>();

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

		private static class ThreadInfo {
		/** Information about the current thread. */
		private 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
		@@ -58,15 +167,10 @@ public class RavenwoodMethodCallLogger {
		public int mDisabledNestLevel = Integer.MAX_VALUE;
		}

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

		/** Classes that should be logged. Uses a map for fast lookup. */
		private static final HashSet<Class> sIgnoreClasses = new HashSet<>();
		private static final HashSet<Class<?>> sIgnoreClasses = new HashSet<>();
		static {
		// The following classes are not interesting...
		sIgnoreClasses.add(android.util.Log.class);
		@@ -92,6 +196,8 @@ public class RavenwoodMethodCallLogger {
		sIgnoreClasses.add(android.os.LocaleList.class);
		sIgnoreClasses.add(android.os.Build.class);
		sIgnoreClasses.add(android.os.SystemProperties.class);
		sIgnoreClasses.add(android.os.UserHandle.class);
		sIgnoreClasses.add(android.os.MessageQueue.class);

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

		@@ -109,20 +215,24 @@ public class RavenwoodMethodCallLogger {
		// 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) {
		@VisibleForTesting
		public boolean shouldIgnoreClass(Class<?> clazz) {
		if (mLogAllMethods) {
		return false;
		}
		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)
		\|\| java.util.Iterator.class.isAssignableFrom(clazz)
		) {
		if ("android.util".equals(clazz.getPackageName())) {
		return true;
		@@ -132,19 +242,22 @@ public class RavenwoodMethodCallLogger {

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

		// 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 true;
		}
		if (clazz.getPackageName().startsWith("repackaged.services.com.android.server.compat")) {
		return true;
		}
		return false;
		}

		private static boolean shouldLog(
		private boolean shouldLog(
		Class<?> methodClass,
		String methodName,
		@SuppressWarnings("UnusedVariable") String methodDescriptor
		@@ -179,51 +292,202 @@ public class RavenwoodMethodCallLogger {
		/**
		* Call this to enable logging.
		*/
		public static void enable(PrintStream out) {
		sEnabled = true;
		sOut = Objects.requireNonNull(out);
		public void enable(@NonNull PrintStream out) {
		mEnabled = true;
		mOut = 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();
		mThreadInfo.get();
		}

		/** Actual method hook entry point.*/
		public static void logMethodCall(
		Class<?> methodClass,
		String methodName,
		String methodDescriptor
		/** Called when a method is called. */
		public void onMethodCalled(
		@NonNull Class<?> methodClass,
		@NonNull String methodName,
		@NonNull String methodDesc
		) {
		if (!sEnabled) {
		if (!mEnabled) {
		return;
		}
		final var ti = sThreadInfo.get();
		synchronized (mAllMethods) {
		var set = mAllMethods.computeIfAbsent(methodClass, (k) -> new HashSet<>());
		set.add(new MethodDesc(methodName, methodDesc));
		}
		var log = buildMethodCallLogLine(methodClass, methodName, methodDesc,
		Thread.currentThread());
		if (log != null) {
		mOut.print(log);
		}
		}

		/** Inner method exposed for testing. */
		@VisibleForTesting
		@Nullable
		public String buildMethodCallLogLine(
		@NonNull Class<?> methodClass,
		@NonNull String methodName,
		@NonNull String methodDesc,
		@NonNull Thread mThread
		) {
		final var ti = mThreadInfo.get();
		final int nestLevel = getNestLevel() - ti.mInitialNestLevel;

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

		if (!shouldLog) {
		ti.mDisabledNestLevel = nestLevel;
		return;
		return null;
		}
		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("] ");
		var sb = new StringBuilder();
		sb.append("# [");
		sb.append(getRawThreadId());
		sb.append(": ");
		sb.append(mThread.getName());
		sb.append("]: ");
		sb.append("[@");
		sb.append(String.format("%2d", nestLevel));
		sb.append("] ");
		for (int i = 0; i < nestLevel; i++) {
		out.print(" ");
		sb.append(" ");
		}
		sb.append(methodClass.getName() + "." + methodName + methodDesc);
		sb.append('\n');
		return sb.toString();
		}

		/** To be overridden for unit tests */
		@VisibleForTesting
		public int getRawThreadId() {
		return RavenwoodRuntimeNative.gettid();
		}

		/**
		* Print all called methods in the form of "policy" file.
		*/
		public void dumpAllCalledMethods() {
		dumpAllCalledMethodsForFileInner(
		CALLED_METHOD_POLICY_FILE, CALLED_METHOD_DUMP_REASON_FILTER_RE);
		}

		/**
		* Print all called methods in the form of "policy" file.
		*/
		@VisibleForTesting
		public void dumpAllCalledMethodsForFileInner(@NonNull String filename,
		@Nullable String reasonFilterRegex) {
		Supplier<OutputStream> opener = () -> {
		try {
		return new FileOutputStream(filename);
		} catch (FileNotFoundException e) {
		SneakyThrow.sneakyThrow(e);
		return null;
		}
		};
		dumpAllCalledMethodsInner(opener, reasonFilterRegex, filename);
		}

		/** Inner method exposed for testing. */
		@VisibleForTesting
		public void dumpAllCalledMethodsInner(@NonNull Supplier<OutputStream> opener,
		@Nullable String resonFilterRegex, @NonNull String outputFileNameForLogging) {
		if (!mEnabled) {
		return;
		}

		synchronized (mAllMethods) {
		if (mAllMethods.isEmpty()) {
		return;
		}
		// "Filter reason" filter.
		final Predicate<String> reasonFilter;
		if (resonFilterRegex == null \|\| resonFilterRegex.isEmpty()) {
		reasonFilter = (reason) -> true;
		} else {
		var pat = Pattern.compile(resonFilterRegex);

		reasonFilter = (reason) -> reason != null && pat.matcher(reason).find();
		}

		var classCount = 0;
		var methodCount = 0;
		try (PrintWriter wr = new PrintWriter(new BufferedOutputStream(opener.get()))) {
		for (var clazz : mAllMethods.keySet().stream()
		.sorted(Comparator.comparing(Class::getName))
		.toList()) {
		classCount++;

		var classMethods = mAllMethods.get(clazz);
		// Set the reasons.
		for (var m : classMethods) {
		m.setReason(getMethodFilterReason(clazz, m.name, m.desc));
		}

		var methods = mAllMethods.get(clazz).stream()
		.filter(m -> reasonFilter.test(m.getReason()))
		.sorted(Comparator.comparing((MethodDesc a) -> a.name)
		.thenComparing(a -> a.desc))
		.toList();

		if (methods.isEmpty()) {
		continue;
		}

		wr.print("class ");
		wr.print(clazz.getName());
		wr.print("\tkeep");
		wr.println();
		for (var method : methods) {
		methodCount++;

		wr.print(" method ");
		wr.print(method.name);
		wr.print(method.desc);
		wr.print("\tkeep");

		var reason = method.getReason();
		if (reason != null && !reason.isEmpty()) {
		wr.print("\t# ");
		wr.print(reason);
		}

		wr.println();
		}
		wr.println();
		}
		Log.i(TAG, String.format("Wrote called methods to %s (%d classes, %d methods)",
		outputFileNameForLogging, classCount, methodCount));
		} catch (Exception e) {
		Log.w(TAG, "Exception while dumping called methods", e);
		}
		}
		}

		/**
		* Find a specified method, and find its "reason" from the HostStubGen annotation.
		*/
		@Nullable
		private static String getMethodFilterReason(
		@NonNull Class<?> clazz,
		@NonNull String methodName,
		@NonNull String methodDesc) {
		// Special case: If the method is "<clinit>", we can't get annotations from it,
		// so let's just use the class's reason instead.
		if ("<clinit>".equals(methodName)) {
		return HostTestUtils.getHostStubGenAnnotationReason(clazz);
		}

		// Find the method, and extract the reason from the annotation, if any.
		var m = RavenwoodAsmUtils.getMethodOrNull(clazz, methodName, methodDesc);
		if (m == null) {
		return null;
		}
		out.println(methodClass.getName() + "." + methodName + methodDescriptor);
		return HostTestUtils.getHostStubGenAnnotationReason(m);
		}
		}

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

+11 −0

Original line number	Diff line number	Diff line
		@@ -45,6 +45,9 @@ import java.util.Map;
		* The output file is created as `/tmp/Ravenwood-stats_[TEST-MODULE=NAME]_[TIMESTAMP].csv`.
		* A symlink to the latest result will be created as
		* `/tmp/Ravenwood-stats_[TEST-MODULE=NAME]_latest.csv`.
		*
		* Also responsible for dumping all called methods in the form of policy file, by calling
		* {@link RavenwoodMethodCallLogger#dumpAllCalledMethodsInner()}, if the method call log is enabled.
		*/
		public class RavenwoodTestStats {
		private static final String TAG = RavenwoodInternalUtils.TAG;
		@@ -227,6 +230,13 @@ public class RavenwoodTestStats {
		return className.substring(0, p);
		}

		private static void createCalledMethodPolicyFile() {
		// Ideally we want to call it only once, when the very last test class finishes,
		// but we don't know which test class is last or not, so let's just do the dump
		// after every test class.
		RavenwoodMethodCallLogger.getInstance().dumpAllCalledMethods();
		}

		public void attachToRunNotifier(RunNotifier notifier) {
		notifier.addListener(mRunListener);
		}
		@@ -261,6 +271,7 @@ public class RavenwoodTestStats {
		Log.d(TAG, "testRunFinished: " + result);
		}

		createCalledMethodPolicyFile();
		dumpAllAndClear();
		}