Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 5d12b205 authored by Treehugger Robot's avatar Treehugger Robot Committed by Gerrit Code Review
Browse files

Merge "Add a better "method call" (optional) log" into main

parents c1b5c042 5cbf9fd1
Loading
Loading
Loading
Loading
+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);
    }
}
+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);
+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

+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())
+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
Loading