Add a better "method call" (optional) log

This logger prints the method name with the thread ID and indentation according
to the call nest level. We also omit logging for certain "uninteresting" methods.

Flag: EXEMPT host test change only
Bug: 292141694
Test: $ANDROID_BUILD_TOP/frameworks/base/ravenwood/scripts/run-ravenwood-tests.sh -s
Test: Manual test: Enable logging by uncommenting --default-method-call-hook
    in ravenwood-standard-options.txt, and check the output

Change-Id: I62084ffad3fff7e11b4b0ec7fd8b682a2a8aceff

2 files changed, 239 insertions, 7 deletions

diff --git a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodMethodCallLogger.java b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodMethodCallLogger.java
new file mode 100644
index 000000000000..7ee9d7a8a5c6
--- /dev/null
+++ b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodMethodCallLogger.java
@@ -0,0 +1,229 @@
+/*
+ * 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);
+    }
+}
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 7af03ed2e6c8..ae88bb234e9d 100644
--- a/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRuntimeEnvironmentController.java
+++ b/ravenwood/junit-impl-src/android/platform/test/ravenwood/RavenwoodRuntimeEnvironmentController.java
@@ -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);