Merge "Fix method call tree log" into main (58ec9344) · Commits · e / os / android_frameworks_base

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

0 → 100644

+57 −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 java.util.HashMap;

		public class RavenwoodInternalUtils {
		private RavenwoodInternalUtils() {
		}

		/**
		* Base class for a simple key value cache. Subclass implements {@link #compute}.
		*/
		public abstract static class MapCache<K, V> {
		private final Object mLock = new Object();

		private final HashMap<K, V> mCache = new HashMap<>();

		/**
		* Subclass implements it.
		*
		* This method may be called for the same key multiple times if access to the same
		* key happens on multiple threads at the same time.
		*/
		protected abstract V compute(K key);

		/**
		* @return the value for a given key, using the cache.
		*/
		public V get(K key) {
		synchronized (mLock) {
		var cached = mCache.get(key);
		if (cached != null) {
		return cached;
		}
		}
		V value = compute(key);
		synchronized (mLock) {
		mCache.put(key, value);
		}
		return value;
		}
		}
		}

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

+74 −67

Original line number	Diff line number	Diff line
		@@ -17,6 +17,7 @@ package android.platform.test.ravenwood;

		import android.annotation.NonNull;
		import android.annotation.Nullable;
		import android.platform.test.ravenwood.RavenwoodInternalUtils.MapCache;
		import android.util.Log;

		import com.android.hoststubgen.hosthelper.HostTestUtils;
		@@ -144,13 +145,6 @@ public class RavenwoodMethodCallLogger {
		@GuardedBy("sAllMethods")
		private final Map<Class<?>, Set<MethodDesc>> mAllMethods = new HashMap<>();

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

		/** Information about the current thread. */
		private class ThreadInfo {
		/**
		@@ -158,13 +152,7 @@ public class RavenwoodMethodCallLogger {
		* 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;
		public final int mInitialNestLevel = Thread.currentThread().getStackTrace().length;
		}

		private final ThreadLocal<ThreadInfo> mThreadInfo = ThreadLocal.withInitial(ThreadInfo::new);
		@@ -178,17 +166,6 @@ public class RavenwoodMethodCallLogger {
		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);
		@@ -220,24 +197,30 @@ public class RavenwoodMethodCallLogger {
		/**
		* Return if a class should be ignored. Uses {link #sIgnoreCladsses}, but
		* we ignore more classes.
		*
		* If we make it operate on class names as strings directly, we wouldn't need
		* the reflections. But we cache the result anyway, so that's not super-critical.
		* Using class objects allow us to easily check inheritance too.
		*/
		@VisibleForTesting
		public boolean shouldIgnoreClass(Class<?> clazz) {
		private boolean shouldIgnoreClass(Class<?> clazz) {
		if (mLogAllMethods) {
		return false;
		}
		if (sIgnoreClasses.contains(clazz)) {
		return true;
		}
		// We want to hide a lot of classes from android.util.
		if ("android.util".equals(clazz.getPackageName())) {
		// 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;
		}
		return false;
		if (clazz.getSimpleName().endsWith("Array")) {
		return true;
		}
		}

		switch (clazz.getSimpleName()) {
		@@ -257,37 +240,59 @@ public class RavenwoodMethodCallLogger {
		return false;
		}

		private boolean shouldLog(
		Class<?> methodClass,
		String methodName,
		@SuppressWarnings("UnusedVariable") String methodDescriptor
		) {
		private boolean shouldLogUncached(Class<?> clazz) {
		// Should we ignore this class?
		if (shouldIgnoreClass(methodClass)) {
		if (shouldIgnoreClass(clazz)) {
		return false;
		}
		// Is it a nested class in a class that should be ignored?
		var host = methodClass.getNestHost();
		if (host != methodClass && shouldIgnoreClass(host)) {
		var host = clazz.getNestHost();
		if (host != clazz && 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")) {
		var pkg = clazz.getPackageName();
		if (pkg.startsWith("android.icu")) {
		return false;
		}

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

		/** Cache for {@link #shouldLog(Class)} */
		private final MapCache<Class<?>, Boolean> mClassEnabledCache = new MapCache<>() {
		@Override
		protected Boolean compute(Class<?> key) {
		return shouldLogUncached(key);
		}
		};

		/** @return whether a class should be logged */
		private boolean shouldLog(Class<?> clazz) {
		return mClassEnabledCache.get(clazz);
		}

		/** Cache for {@link #shouldLog(String)} to avoid repeated reflections. */
		private final MapCache<String, Boolean> mStringClassEnabledCache = new MapCache<>() {
		@Override
		protected Boolean compute(String className) {
		try {
		Class<?> c = Class.forName(className);
		if (!shouldLog(c)) {
		return false;
		}
		} catch (ClassNotFoundException e) {
		// Assume this class is loggable.
		}
		return true;
		}
		};

		/** @return whether a class should be logged */
		@VisibleForTesting
		public boolean shouldLog(String className) {
		return mStringClassEnabledCache.get(className);
		}

		/**
		* Call this to enable logging.
		@@ -322,29 +327,31 @@ public class RavenwoodMethodCallLogger {
		}

		/** Inner method exposed for testing. */
		@VisibleForTesting
		@Nullable
		public String buildMethodCallLogLine(
		private 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 null; // Still ignore.
		if (!shouldLog(methodClass)) {
		return null;
		}
		final boolean shouldLog = shouldLog(methodClass, methodName, methodDesc);

		if (!shouldLog) {
		ti.mDisabledNestLevel = nestLevel;
		final var ti = mThreadInfo.get();
		final var stack = Thread.currentThread().getStackTrace();
		final int nestLevel = stack.length - ti.mInitialNestLevel;

		// If a method is called from a "ignored" class, we don't want to log it,
		// even if this method itself is loggable.
		//
		// To do so, we have to check all the classes in the stacktrace (unfortunately) every time.
		// That's because we can't re-construct the whole call tree only from the information
		// from the method call log call, because we don't know when we exit each method.
		for (var sf : stack) {
		if (!shouldLog(sf.getClassName())) {
		return null;
		}
		ti.mDisabledNestLevel = Integer.MAX_VALUE;

		}
		var sb = new StringBuilder();
		sb.append("# [");
		sb.append(getRawThreadId());

ravenwood/tests/coretest/test/com/android/ravenwoodtest/unittests/RavenwoodMethodCallLoggerTest.java

+20 −79

Original line number	Diff line number	Diff line
		@@ -18,7 +18,6 @@ package com.android.ravenwoodtest.unittests;
		import static com.google.common.truth.Truth.assertThat;

		import static org.junit.Assert.assertFalse;
		import static org.junit.Assert.assertNull;
		import static org.junit.Assert.assertTrue;

		import android.content.Context;
		@@ -58,95 +57,37 @@ public class RavenwoodMethodCallLoggerTest {

		/** This allows overriding the nest level. */
		public Integer mNestLevel = null;

		@Override
		public int getNestLevel() {
		return (mNestLevel != null) ? mNestLevel : super.getNestLevel();
		}
		}

		private void assertLogged(Class<?> clazz) {
		assertFalse(clazz + " should be logged", mTarget.shouldIgnoreClass(clazz));
		private void assertLogged(String className) {
		assertTrue(className + " should be logged", mTarget.shouldLog(className));
		}

		private void assertNotLogged(Class<?> clazz) {
		assertTrue(clazz + " should not be logged", mTarget.shouldIgnoreClass(clazz));
		private void assertNotLogged(String className) {
		assertFalse(className + " should not be logged", mTarget.shouldLog(className));
		}

		@Test
		public void testShouldIgnoreClass() {
		assertNotLogged(android.util.Log.class);
		assertNotLogged(android.util.SparseArray.class);
		assertNotLogged(android.util.ArrayMap.class);
		assertNotLogged(android.app.EventLogTags.class);

		assertLogged(android.app.ActivityThread.class);
		assertLogged(android.content.Context.class);
		}

		/**
		* Unit test for buildMethodCallLogLine().
		*/
		@Test
		public void testBuildLogLine() {
		Thread thread = new Thread("caller-thread");
		StringBuilder sb = new StringBuilder();

		// Note, buildMethodCallLogLine() doesn't check "mEnabled", so no need to call enable().

		// Here, we should only use public APIs that won't suddenly be removed
		mTarget.mNestLevel = 0;
		sb.append(mTarget.buildMethodCallLogLine(
		Context.class,
		"getPackageName",
		"()Ljava/lang/String;",
		thread));

		mTarget.mNestLevel = 1;
		sb.append(mTarget.buildMethodCallLogLine(
		Context.class,
		"getBasePackageName",
		"()Ljava/lang/String;",
		thread));

		// This shouldn't be logged, so the method should return null.
		mTarget.mNestLevel = 2;
		assertNull(mTarget.buildMethodCallLogLine(
		Log.class,
		"d",
		"(Ljava/lang/String;Ljava/lang/String;)V",
		thread));

		// Called by an ignored method, so this shouldn't be logged either.
		mTarget.mNestLevel = 3;
		assertNull(mTarget.buildMethodCallLogLine(
		Context.class,
		"getBasePackageName",
		"()Ljava/lang/String;",
		thread));

		// This should be logged again.
		mTarget.mNestLevel = 1;
		sb.append(mTarget.buildMethodCallLogLine(
		Context.class,
		"getOpPackgeName",
		"()Ljava/lang/String;",
		thread));
		String expected = """
		# [123: caller-thread]: [@ 0] android.content.Context.getPackageName()Ljava/lang/String;
		# [123: caller-thread]: [@ 1] android.content.Context.getBasePackageName()Ljava/lang/String;
		# [123: caller-thread]: [@ 1] android.content.Context.getOpPackgeName()Ljava/lang/String;
		""";
		assertThat(sb.toString().trim()).isEqualTo(expected.trim());
		public void testShouldLog() {
		assertNotLogged("android.util.Log");
		assertNotLogged("android.util.ArrayMap");
		assertNotLogged("android.util.SparseArray");
		assertNotLogged("android.app.EventLogTags");
		assertNotLogged("android.os.Build");
		assertNotLogged("android.os.Build$VERSION"); // Inner class follows the outer class policy.

		assertLogged("android.app.ActivityThread");
		assertLogged("android.content.Context");
		assertLogged("android.util.DebugUtils");
		assertLogged("android.content.pm.PackageManager");
		assertLogged("android.content.pm.PackageManager$NameNotFoundException");
		}

		/**
		* More complete "end-to-end" test that exercises more of the target code.
		* Complete "end-to-end" test that exercises more of the target code.
		*
		* - It doesn't inject the nest level or the caller thread and let RavenwoodMethodCallLogger
		* figure them out. (That means we can't adjust the nest level, and because
		* RavenwoodMethodCallLogger gets the nest level from the stacktrace, all the log lines
		* will get the same nest level.)
		* Note, method call log uses the real stacktrace to figure out the nest level.
		* So all the calls look "flat".
		*/
		@Test
		public void testEndToEnd() throws Exception {