diff options
| -rw-r--r-- | services/core/java/com/android/server/utils/AnrTimer.java | 481 | ||||
| -rw-r--r-- | services/core/jni/Android.bp | 8 | ||||
| -rw-r--r-- | services/core/jni/com_android_server_utils_AnrTimer.cpp | 918 | ||||
| -rw-r--r-- | services/core/jni/onload.cpp | 2 | ||||
| -rw-r--r-- | services/tests/servicestests/jni/Android.bp | 3 | ||||
| -rw-r--r-- | services/tests/servicestests/jni/onload.cpp | 2 | ||||
| -rw-r--r-- | services/tests/servicestests/src/com/android/server/utils/AnrTimerTest.java | 234 |
7 files changed, 1560 insertions, 88 deletions
diff --git a/services/core/java/com/android/server/utils/AnrTimer.java b/services/core/java/com/android/server/utils/AnrTimer.java index 7b5192c4bd6b..e3aba0f6bc6f 100644 --- a/services/core/java/com/android/server/utils/AnrTimer.java +++ b/services/core/java/com/android/server/utils/AnrTimer.java @@ -16,21 +16,30 @@ package com.android.server.utils; +import static android.text.TextUtils.formatSimple; + import android.annotation.NonNull; import android.os.Handler; import android.os.Message; import android.os.SystemClock; import android.os.Trace; +import android.text.TextUtils; import android.text.format.TimeMigrationUtils; +import android.util.ArrayMap; import android.util.IndentingPrintWriter; import android.util.Log; +import android.util.LongSparseArray; +import android.util.SparseArray; import com.android.internal.annotations.GuardedBy; +import com.android.internal.annotations.Keep; import com.android.internal.annotations.VisibleForTesting; import com.android.internal.util.RingBuffer; +import java.lang.ref.WeakReference; import java.io.PrintWriter; import java.util.Arrays; +import java.util.ArrayList; import java.util.Objects; /** @@ -60,9 +69,14 @@ import java.util.Objects; * is restarted with the extension timeout. If extensions are disabled or if the extension is zero, * the client process is notified of the expiration. * + * <p>Instances use native resources but not system resources when the feature is enabled. + * Instances should be explicitly closed unless they are being closed as part of process + * exit. (So, instances in system server generally need not be explicitly closed since they are + * created during process start and will last until process exit.) + * * @hide */ -public class AnrTimer<V> { +public class AnrTimer<V> implements AutoCloseable { /** * The log tag. @@ -87,6 +101,12 @@ public class AnrTimer<V> { private static final long TRACE_TAG = Trace.TRACE_TAG_ACTIVITY_MANAGER; /** + * Enable tracing from the time a timer expires until it is accepted or discarded. This is + * used to diagnose long latencies in the client. + */ + private static final boolean ENABLE_TRACING = false; + + /** * Return true if the feature is enabled. By default, the value is take from the Flags class * but it can be changed for local testing. */ @@ -103,6 +123,9 @@ public class AnrTimer<V> { } } + /** The default injector. */ + private static final Injector sDefaultInjector = new Injector(); + /** * An error is defined by its issue, the operation that detected the error, the tag of the * affected service, a short stack of the bad call, and the stringified arg associated with @@ -160,41 +183,46 @@ public class AnrTimer<V> { /** A lock for the AnrTimer instance. */ private final Object mLock = new Object(); - /** - * The total number of timers started. - */ + /** The map from client argument to the associated timer ID. */ + @GuardedBy("mLock") + private final ArrayMap<V, Integer> mTimerIdMap = new ArrayMap<>(); + + /** Reverse map from timer ID to client argument. */ + @GuardedBy("mLock") + private final SparseArray<V> mTimerArgMap = new SparseArray<>(); + + /** The highwater mark of started, but not closed, timers. */ + @GuardedBy("mLock") + private int mMaxStarted = 0; + + /** The total number of timers started. */ @GuardedBy("mLock") private int mTotalStarted = 0; - /** - * The total number of errors detected. - */ + /** The total number of errors detected. */ @GuardedBy("mLock") private int mTotalErrors = 0; - /** - * The handler for messages sent from this instance. - */ + /** The total number of timers that have expired. */ + @GuardedBy("mLock") + private int mTotalExpired = 0; + + /** The handler for messages sent from this instance. */ private final Handler mHandler; - /** - * The message type for messages sent from this interface. - */ + /** The message type for messages sent from this interface. */ private final int mWhat; - /** - * A label that identifies the AnrTimer associated with a Timer in log messages. - */ + /** A label that identifies the AnrTimer associated with a Timer in log messages. */ private final String mLabel; - /** - * Whether this timer instance supports extending timeouts. - */ + /** Whether this timer instance supports extending timeouts. */ private final boolean mExtend; - /** - * The top-level switch for the feature enabled or disabled. - */ + /** The injector used to create this instance. This is only used for testing. */ + private final Injector mInjector; + + /** The top-level switch for the feature enabled or disabled. */ private final FeatureSwitch mFeature; /** @@ -223,7 +251,27 @@ public class AnrTimer<V> { mWhat = what; mLabel = label; mExtend = extend; - mFeature = new FeatureDisabled(); + mInjector = injector; + boolean enabled = mInjector.anrTimerServiceEnabled() && nativeTimersSupported(); + mFeature = createFeatureSwitch(enabled); + } + + // Return the correct feature. FeatureEnabled is returned if and only if the feature is + // flag-enabled and if the native shadow was successfully created. Otherwise, FeatureDisabled + // is returned. + private FeatureSwitch createFeatureSwitch(boolean enabled) { + if (!enabled) { + return new FeatureDisabled(); + } else { + try { + return new FeatureEnabled(); + } catch (RuntimeException e) { + // Something went wrong in the native layer. Log the error and fall back on the + // feature-disabled logic. + Log.e(TAG, e.toString()); + return new FeatureDisabled(); + } + } } /** @@ -245,7 +293,7 @@ public class AnrTimer<V> { * @param extend A flag to indicate if expired timers can be granted extensions. */ public AnrTimer(@NonNull Handler handler, int what, @NonNull String label, boolean extend) { - this(handler, what, label, extend, new Injector()); + this(handler, what, label, extend, sDefaultInjector); } /** @@ -272,19 +320,44 @@ public class AnrTimer<V> { } /** + * Start a trace on the timer. The trace is laid down in the AnrTimerTrack. + */ + private void traceBegin(int timerId, int pid, int uid, String what) { + if (ENABLE_TRACING) { + final String label = formatSimple("%s(%d,%d,%s)", what, pid, uid, mLabel); + final int cookie = timerId; + Trace.asyncTraceForTrackBegin(TRACE_TAG, TRACK, label, cookie); + } + } + + /** + * End a trace on the timer. + */ + private void traceEnd(int timerId) { + if (ENABLE_TRACING) { + final int cookie = timerId; + Trace.asyncTraceForTrackEnd(TRACE_TAG, TRACK, cookie); + } + } + + /** * The FeatureSwitch class provides a quick switch between feature-enabled behavior and * feature-disabled behavior. */ private abstract class FeatureSwitch { abstract void start(@NonNull V arg, int pid, int uid, long timeoutMs); - abstract void cancel(@NonNull V arg); + abstract boolean cancel(@NonNull V arg); - abstract void accept(@NonNull V arg); + abstract boolean accept(@NonNull V arg); - abstract void discard(@NonNull V arg); + abstract boolean discard(@NonNull V arg); abstract boolean enabled(); + + abstract void dump(PrintWriter pw, boolean verbose); + + abstract void close(); } /** @@ -301,18 +374,21 @@ public class AnrTimer<V> { /** Cancel a timer by removing the message from the client's handler. */ @Override - void cancel(@NonNull V arg) { + boolean cancel(@NonNull V arg) { mHandler.removeMessages(mWhat, arg); + return true; } /** accept() is a no-op when the feature is disabled. */ @Override - void accept(@NonNull V arg) { + boolean accept(@NonNull V arg) { + return true; } /** discard() is a no-op when the feature is disabled. */ @Override - void discard(@NonNull V arg) { + boolean discard(@NonNull V arg) { + return true; } /** The feature is not enabled. */ @@ -320,12 +396,179 @@ public class AnrTimer<V> { boolean enabled() { return false; } + + /** dump() is a no-op when the feature is disabled. */ + @Override + void dump(PrintWriter pw, boolean verbose) { + } + + /** close() is a no-op when the feature is disabled. */ + @Override + void close() { + } + } + + /** + * A static list of AnrTimer instances. The list is traversed by dumpsys. Only instances + * using native resources are included. + */ + @GuardedBy("sAnrTimerList") + private static final LongSparseArray<WeakReference<AnrTimer>> sAnrTimerList = + new LongSparseArray<>(); + + /** + * The FeatureEnabled class enables the AnrTimer logic. It is used when the AnrTimer service + * is enabled via Flags.anrTimerServiceEnabled. + */ + private class FeatureEnabled extends FeatureSwitch { + + /** + * The native timer that supports this instance. The value is set to non-zero when the + * native timer is created and it is set back to zero when the native timer is freed. + */ + private long mNative = 0; + + /** Fetch the native tag (an integer) for the given label. */ + FeatureEnabled() { + mNative = nativeAnrTimerCreate(mLabel); + if (mNative == 0) throw new IllegalArgumentException("unable to create native timer"); + synchronized (sAnrTimerList) { + sAnrTimerList.put(mNative, new WeakReference(AnrTimer.this)); + } + } + + /** + * Start a timer. + */ + @Override + void start(@NonNull V arg, int pid, int uid, long timeoutMs) { + synchronized (mLock) { + if (mTimerIdMap.containsKey(arg)) { + // There is an existing timer. Cancel it. + cancel(arg); + } + int timerId = nativeAnrTimerStart(mNative, pid, uid, timeoutMs, mExtend); + if (timerId > 0) { + mTimerIdMap.put(arg, timerId); + mTimerArgMap.put(timerId, arg); + mTotalStarted++; + mMaxStarted = Math.max(mMaxStarted, mTimerIdMap.size()); + } else { + throw new RuntimeException("unable to start timer"); + } + } + } + + /** + * Cancel a timer. No error is reported if the timer is not found because some clients + * cancel timers from common code that runs even if a timer was never started. + */ + @Override + boolean cancel(@NonNull V arg) { + synchronized (mLock) { + Integer timer = removeLocked(arg); + if (timer == null) { + return false; + } + if (!nativeAnrTimerCancel(mNative, timer)) { + // There may be an expiration message in flight. Cancel it. + mHandler.removeMessages(mWhat, arg); + return false; + } + return true; + } + } + + /** + * Accept a timer in the framework-level handler. The timeout has been accepted and the + * timeout handler is executing. + */ + @Override + boolean accept(@NonNull V arg) { + synchronized (mLock) { + Integer timer = removeLocked(arg); + if (timer == null) { + notFoundLocked("accept", arg); + return false; + } + nativeAnrTimerAccept(mNative, timer); + traceEnd(timer); + return true; + } + } + + /** + * Discard a timer in the framework-level handler. For whatever reason, the timer is no + * longer interesting. No statistics are collected. Return false if the time was not + * found. + */ + @Override + boolean discard(@NonNull V arg) { + synchronized (mLock) { + Integer timer = removeLocked(arg); + if (timer == null) { + notFoundLocked("discard", arg); + return false; + } + nativeAnrTimerDiscard(mNative, timer); + traceEnd(timer); + return true; + } + } + + /** The feature is enabled. */ + @Override + boolean enabled() { + return true; + } + + /** Dump statistics from the native layer. */ + @Override + void dump(PrintWriter pw, boolean verbose) { + synchronized (mLock) { + if (mNative != 0) { + nativeAnrTimerDump(mNative, verbose); + } else { + pw.println("closed"); + } + } + } + + /** Free native resources. */ + @Override + void close() { + // Remove self from the list of active timers. + synchronized (sAnrTimerList) { + sAnrTimerList.remove(mNative); + } + synchronized (mLock) { + if (mNative != 0) nativeAnrTimerClose(mNative); + mNative = 0; + } + } + + /** + * Delete the entries associated with arg from the maps and return the ID of the timer, if + * any. + */ + @GuardedBy("mLock") + private Integer removeLocked(V arg) { + Integer r = mTimerIdMap.remove(arg); + if (r != null) { + synchronized (mTimerArgMap) { + mTimerArgMap.remove(r); + } + } + return r; + } } /** * Start a timer associated with arg. The same object must be used to cancel, accept, or * discard a timer later. If a timer already exists with the same arg, then the existing timer - * is canceled and a new timer is created. + * is canceled and a new timer is created. The timeout is signed but negative delays are + * nonsensical. Rather than throw an exception, timeouts less than 0ms are forced to 0ms. This + * allows a client to deliver an immediate timeout via the AnrTimer. * * @param arg The key by which the timer is known. This is never examined or modified. * @param pid The Linux process ID of the target being timed. @@ -333,25 +576,39 @@ public class AnrTimer<V> { * @param timeoutMs The timer timeout, in milliseconds. */ public void start(@NonNull V arg, int pid, int uid, long timeoutMs) { + if (timeoutMs < 0) timeoutMs = 0; mFeature.start(arg, pid, uid, timeoutMs); } /** * Cancel the running timer associated with arg. The timer is forgotten. If the timer has - * expired, the call is treated as a discard. No errors are reported if the timer does not - * exist or if the timer has expired. + * expired, the call is treated as a discard. The function returns true if a running timer was + * found, and false if an expired timer was found or if no timer was found. After this call, + * the timer does not exist. + * + * Note: the return value is always true if the feature is not enabled. + * + * @param arg The key by which the timer is known. This is never examined or modified. + * @return True if a running timer was canceled. */ - public void cancel(@NonNull V arg) { - mFeature.cancel(arg); + public boolean cancel(@NonNull V arg) { + return mFeature.cancel(arg); } /** * Accept the expired timer associated with arg. This indicates that the caller considers the - * timer expiration to be a true ANR. (See {@link #discard} for an alternate response.) It is - * an error to accept a running timer, however the running timer will be canceled. + * timer expiration to be a true ANR. (See {@link #discard} for an alternate response.) The + * function returns true if an expired timer was found and false if a running timer was found or + * if no timer was found. After this call, the timer does not exist. It is an error to accept + * a running timer, however, the running timer will be canceled. + * + * Note: the return value is always true if the feature is not enabled. + * + * @param arg The key by which the timer is known. This is never examined or modified. + * @return True if an expired timer was accepted. */ - public void accept(@NonNull V arg) { - mFeature.accept(arg); + public boolean accept(@NonNull V arg) { + return mFeature.accept(arg); } /** @@ -359,11 +616,57 @@ public class AnrTimer<V> { * timer expiration to be a false ANR. ((See {@link #accept} for an alternate response.) One * reason to discard an expired timer is if the process being timed was also being debugged: * such a process could be stopped at a breakpoint and its failure to respond would not be an - * error. It is an error to discard a running timer, however the running timer will be - * canceled. + * error. After this call thie timer does not exist. It is an error to discard a running timer, + * however the running timer will be canceled. + * + * Note: the return value is always true if the feature is not enabled. + * + * @param arg The key by which the timer is known. This is never examined or modified. + * @return True if an expired timer was discarded. + */ + public boolean discard(@NonNull V arg) { + return mFeature.discard(arg); + } + + /** + * The notifier that a timer has fired. The timerId and original pid/uid are supplied. This + * method is called from native code. This method takes mLock so that a timer cannot expire + * in the middle of another operation (like start or cancel). + */ + @Keep + private boolean expire(int timerId, int pid, int uid) { + traceBegin(timerId, pid, uid, "expired"); + V arg = null; + synchronized (mLock) { + arg = mTimerArgMap.get(timerId); + if (arg == null) { + Log.e(TAG, formatSimple("failed to expire timer %s:%d : arg not found", + mLabel, timerId)); + mTotalErrors++; + return false; + } + mTotalExpired++; + } + mHandler.sendMessage(Message.obtain(mHandler, mWhat, arg)); + return true; + } + + /** + * Close the object and free any native resources. */ - public void discard(@NonNull V arg) { - mFeature.discard(arg); + public void close() { + mFeature.close(); + } + + /** + * Ensure any native resources are freed when the object is GC'ed. Best practice is to close + * the object explicitly, but overriding finalize() avoids accidental leaks. + */ + @SuppressWarnings("Finalize") + @Override + protected void finalize() throws Throwable { + close(); + super.finalize(); } /** @@ -373,8 +676,11 @@ public class AnrTimer<V> { synchronized (mLock) { pw.format("timer: %s\n", mLabel); pw.increaseIndent(); - pw.format("started=%d errors=%d\n", mTotalStarted, mTotalErrors); + pw.format("started=%d maxStarted=%d running=%d expired=%d errors=%d\n", + mTotalStarted, mMaxStarted, mTimerIdMap.size(), + mTotalExpired, mTotalErrors); pw.decreaseIndent(); + mFeature.dump(pw, false); } } @@ -386,6 +692,13 @@ public class AnrTimer<V> { } /** + * The current time in milliseconds. + */ + private static long now() { + return SystemClock.uptimeMillis(); + } + + /** * Dump all errors to the output stream. */ private static void dumpErrors(IndentingPrintWriter ipw) { @@ -422,23 +735,89 @@ public class AnrTimer<V> { mTotalErrors++; } - /** - * Log an error about a timer not found. - */ + /** Record an error about a timer not found. */ @GuardedBy("mLock") private void notFoundLocked(String operation, Object arg) { recordErrorLocked(operation, "notFound", arg); } - /** - * Dumpsys output. - */ - public static void dump(@NonNull PrintWriter pw, boolean verbose) { + /** Dumpsys output, allowing for overrides. */ + @VisibleForTesting + static void dump(@NonNull PrintWriter pw, boolean verbose, @NonNull Injector injector) { + if (!injector.anrTimerServiceEnabled()) return; + final IndentingPrintWriter ipw = new IndentingPrintWriter(pw); ipw.println("AnrTimer statistics"); ipw.increaseIndent(); + synchronized (sAnrTimerList) { + final int size = sAnrTimerList.size(); + ipw.println("reporting " + size + " timers"); + for (int i = 0; i < size; i++) { + AnrTimer a = sAnrTimerList.valueAt(i).get(); + if (a != null) a.dump(ipw); + } + } if (verbose) dumpErrors(ipw); ipw.format("AnrTimerEnd\n"); ipw.decreaseIndent(); } + + /** Dumpsys output. There is no output if the feature is not enabled. */ + public static void dump(@NonNull PrintWriter pw, boolean verbose) { + dump(pw, verbose, sDefaultInjector); + } + + /** + * Return true if the native timers are supported. Native timers are supported if the method + * nativeAnrTimerSupported() can be executed and it returns true. + */ + private static boolean nativeTimersSupported() { + try { + return nativeAnrTimerSupported(); + } catch (java.lang.UnsatisfiedLinkError e) { + return false; + } + } + + /** + * Native methods + */ + + /** Return true if the native AnrTimer code is operational. */ + private static native boolean nativeAnrTimerSupported(); + + /** + * Create a new native timer with the given key and name. The key is not used by the native + * code but it is returned to the Java layer in the expiration handler. The name is only for + * logging. Unlike the other methods, this is an instance method: the "this" parameter is + * passed into the native layer. + */ + private native long nativeAnrTimerCreate(String name); + + /** Release the native resources. No further operations are premitted. */ + private static native int nativeAnrTimerClose(long service); + + /** Start a timer and return its ID. Zero is returned on error. */ + private static native int nativeAnrTimerStart(long service, int pid, int uid, long timeoutMs, + boolean extend); + + /** + * Cancel a timer by ID. Return true if the timer was running and canceled. Return false if + * the timer was not found or if the timer had already expired. + */ + private static native boolean nativeAnrTimerCancel(long service, int timerId); + + /** Accept an expired timer by ID. Return true if the timer was found. */ + private static native boolean nativeAnrTimerAccept(long service, int timerId); + + /** Discard an expired timer by ID. Return true if the timer was found. */ + private static native boolean nativeAnrTimerDiscard(long service, int timerId); + + /** Prod the native library to log a few statistics. */ + private static native void nativeAnrTimerDump(long service, boolean verbose); + + // This is not a native method but it is a native interface, in the sense that it is called from + // the native layer to report timer expiration. The function must return true if the expiration + // message is delivered to the upper layers and false if it could not be delivered. + // private boolean expire(int timerId, int pid, int uid); } diff --git a/services/core/jni/Android.bp b/services/core/jni/Android.bp index b19f3d813985..dfa9dcecfbb5 100644 --- a/services/core/jni/Android.bp +++ b/services/core/jni/Android.bp @@ -79,6 +79,7 @@ cc_library_static { ":lib_cachedAppOptimizer_native", ":lib_gameManagerService_native", ":lib_oomConnection_native", + ":lib_anrTimer_native", ], include_dirs: [ @@ -246,3 +247,10 @@ filegroup { name: "lib_oomConnection_native", srcs: ["com_android_server_am_OomConnection.cpp"], } + +filegroup { + name: "lib_anrTimer_native", + srcs: [ + "com_android_server_utils_AnrTimer.cpp", + ], +} diff --git a/services/core/jni/com_android_server_utils_AnrTimer.cpp b/services/core/jni/com_android_server_utils_AnrTimer.cpp new file mode 100644 index 000000000000..97b18fac91f4 --- /dev/null +++ b/services/core/jni/com_android_server_utils_AnrTimer.cpp @@ -0,0 +1,918 @@ +/* + * Copyright (C) 2023 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. + */ + +#include <time.h> +#include <pthread.h> +#include <sys/timerfd.h> +#include <inttypes.h> + +#include <algorithm> +#include <list> +#include <memory> +#include <set> +#include <string> +#include <vector> + +#define LOG_TAG "AnrTimerService" + +#include <jni.h> +#include <nativehelper/JNIHelp.h> +#include "android_runtime/AndroidRuntime.h" +#include "core_jni_helpers.h" + +#include <utils/Mutex.h> +#include <utils/Timers.h> + +#include <utils/Log.h> +#include <utils/Timers.h> +#include <android-base/logging.h> +#include <android-base/stringprintf.h> +#include <android-base/unique_fd.h> + +using ::android::base::StringPrintf; + + +// Native support is unavailable on WIN32 platforms. This macro preemptively disables it. +#ifdef _WIN32 +#define NATIVE_SUPPORT 0 +#else +#define NATIVE_SUPPORT 1 +#endif + +namespace android { + +// using namespace android; + +// Almost nothing in this module needs to be in the android namespace. +namespace { + +// If not on a Posix system, create stub timerfd methods. These are defined to allow +// compilation. They are not functional. Also, they do not leak outside this compilation unit. +#ifdef _WIN32 +int timer_create() { + return -1; +} +int timer_settime(int, int, void const *, void *) { + return -1; +} +#else +int timer_create() { + return timerfd_create(CLOCK_MONOTONIC, TFD_CLOEXEC); +} +int timer_settime(int fd, int flags, const struct itimerspec *new_value, + struct itimerspec *_Nullable old_value) { + return timerfd_settime(fd, flags, new_value, old_value); +} +#endif + +// A local debug flag that gates a set of log messages for debug only. This is normally const +// false so the debug statements are not included in the image. The flag can be set true in a +// unit test image to debug test failures. +const bool DEBUG = false; + +// Return the current time in nanoseconds. This time is relative to system boot. +nsecs_t now() { + return systemTime(SYSTEM_TIME_MONOTONIC); +} + +/** + * This class encapsulates the anr timer service. The service manages a list of individual + * timers. A timer is either Running or Expired. Once started, a timer may be canceled or + * accepted. Both actions collect statistics about the timer and then delete it. An expired + * timer may also be discarded, which deletes the timer without collecting any statistics. + * + * All public methods in this class are thread-safe. + */ +class AnrTimerService { + private: + class ProcessStats; + class Timer; + + public: + + // The class that actually runs the clock. + class Ticker; + + // A timer is identified by a timer_id_t. Timer IDs are unique in the moment. + using timer_id_t = uint32_t; + + // A manifest constant. No timer is ever created with this ID. + static const timer_id_t NOTIMER = 0; + + // A notifier is called with a timer ID, the timer's tag, and the client's cookie. The pid + // and uid that were originally assigned to the timer are passed as well. + using notifier_t = bool (*)(timer_id_t, int pid, int uid, void* cookie, jweak object); + + enum Status { + Invalid, + Running, + Expired, + Canceled + }; + + /** + * Create a timer service. The service is initialized with a name used for logging. The + * constructor is also given the notifier callback, and two cookies for the callback: the + * traditional void* and an int. + */ + AnrTimerService(char const* label, notifier_t notifier, void* cookie, jweak jtimer, Ticker*); + + // Delete the service and clean up memory. + ~AnrTimerService(); + + // Start a timer and return the associated timer ID. It does not matter if the same pid/uid + // are already in the running list. Once start() is called, one of cancel(), accept(), or + // discard() must be called to clean up the internal data structures. + timer_id_t start(int pid, int uid, nsecs_t timeout, bool extend); + + // Cancel a timer and remove it from all lists. This is called when the event being timed + // has occurred. If the timer was Running, the function returns true. The other + // possibilities are that the timer was Expired or non-existent; in both cases, the function + // returns false. + bool cancel(timer_id_t timerId); + + // Accept a timer and remove it from all lists. This is called when the upper layers accept + // that a timer has expired. If the timer was Expired, the function returns true. The + // other possibilities are tha the timer was Running or non-existing; in both cases, the + // function returns false. + bool accept(timer_id_t timerId); + + // Discard a timer without collecting any statistics. This is called when the upper layers + // recognize that a timer expired but decide the expiration is not significant. If the + // timer was Expired, the function returns true. The other possibilities are tha the timer + // was Running or non-existing; in both cases, the function returns false. + bool discard(timer_id_t timerId); + + // A timer has expired. + void expire(timer_id_t); + + // Dump a small amount of state to the log file. + void dump(bool verbose) const; + + // Return the Java object associated with this instance. + jweak jtimer() const { + return notifierObject_; + } + + private: + // The service cannot be copied. + AnrTimerService(AnrTimerService const &) = delete; + + // Insert a timer into the running list. The lock must be held by the caller. + void insert(const Timer&); + + // Remove a timer from the lists and return it. The lock must be held by the caller. + Timer remove(timer_id_t timerId); + + // Return a string representation of a status value. + static char const *statusString(Status); + + // The name of this service, for logging. + std::string const label_; + + // The callback that is invoked when a timer expires. + notifier_t const notifier_; + + // The two cookies passed to the notifier. + void* notifierCookie_; + jweak notifierObject_; + + // The global lock + mutable Mutex lock_; + + // The list of all timers that are still running. This is sorted by ID for fast lookup. + std::set<Timer> running_; + + // The maximum number of active timers. + size_t maxActive_; + + // Simple counters + struct Counters { + // The number of timers started, canceled, accepted, discarded, and expired. + size_t started; + size_t canceled; + size_t accepted; + size_t discarded; + size_t expired; + + // The number of times there were zero active timers. + size_t drained; + + // The number of times a protocol error was seen. + size_t error; + }; + + Counters counters_; + + // The clock used by this AnrTimerService. + Ticker *ticker_; +}; + +class AnrTimerService::ProcessStats { + public: + nsecs_t cpu_time; + nsecs_t cpu_delay; + + ProcessStats() : + cpu_time(0), + cpu_delay(0) { + } + + // Collect all statistics for a process. Return true if the fill succeeded and false if it + // did not. If there is any problem, the statistics are zeroed. + bool fill(int pid) { + cpu_time = 0; + cpu_delay = 0; + + char path[PATH_MAX]; + snprintf(path, sizeof(path), "/proc/%u/schedstat", pid); + ::android::base::unique_fd fd(open(path, O_RDONLY | O_CLOEXEC)); + if (!fd.ok()) { + return false; + } + char buffer[128]; + ssize_t len = read(fd, buffer, sizeof(buffer)); + if (len <= 0) { + return false; + } + if (len >= sizeof(buffer)) { + ALOGE("proc file too big: %s", path); + return false; + } + buffer[len] = 0; + unsigned long t1; + unsigned long t2; + if (sscanf(buffer, "%lu %lu", &t1, &t2) != 2) { + return false; + } + cpu_time = t1; + cpu_delay = t2; + return true; + } +}; + +class AnrTimerService::Timer { + public: + // A unique ID assigned when the Timer is created. + timer_id_t const id; + + // The creation parameters. The timeout is the original, relative timeout. + int const pid; + int const uid; + nsecs_t const timeout; + bool const extend; + + // The state of this timer. + Status status; + + // The scheduled timeout. This is an absolute time. It may be extended. + nsecs_t scheduled; + + // True if this timer has been extended. + bool extended; + + // Bookkeeping for extensions. The initial state of the process. This is collected only if + // the timer is extensible. + ProcessStats initial; + + // The default constructor is used to create timers that are Invalid, representing the "not + // found" condition when a collection is searched. + Timer() : + id(NOTIMER), + pid(0), + uid(0), + timeout(0), + extend(false), + status(Invalid), + scheduled(0), + extended(false) { + } + + // This constructor creates a timer with the specified id. This can be used as the argument + // to find(). + Timer(timer_id_t id) : + id(id), + pid(0), + uid(0), + timeout(0), + extend(false), + status(Invalid), + scheduled(0), + extended(false) { + } + + // Create a new timer. This starts the timer. + Timer(int pid, int uid, nsecs_t timeout, bool extend) : + id(nextId()), + pid(pid), + uid(uid), + timeout(timeout), + extend(extend), + status(Running), + scheduled(now() + timeout), + extended(false) { + if (extend && pid != 0) { + initial.fill(pid); + } + } + + // Cancel a timer. Return the headroom (which may be negative). This does not, as yet, + // account for extensions. + void cancel() { + ALOGW_IF(DEBUG && status != Running, "cancel %s", toString().c_str()); + status = Canceled; + } + + // Expire a timer. Return true if the timer is expired and false otherwise. The function + // returns false if the timer is eligible for extension. If the function returns false, the + // scheduled time is updated. + bool expire() { + ALOGI_IF(DEBUG, "expire %s", toString().c_str()); + nsecs_t extension = 0; + if (extend && !extended) { + // Only one extension is permitted. + extended = true; + ProcessStats current; + current.fill(pid); + extension = current.cpu_delay - initial.cpu_delay; + if (extension < 0) extension = 0; + if (extension > timeout) extension = timeout; + } + if (extension == 0) { + status = Expired; + } else { + scheduled += extension; + } + return status == Expired; + } + + // Accept a timeout. + void accept() { + } + + // Discard a timeout. + void discard() { + } + + // Timers are sorted by id, which is unique. This provides fast lookups. + bool operator<(Timer const &r) const { + return id < r.id; + } + + bool operator==(timer_id_t r) const { + return id == r; + } + + std::string toString() const { + return StringPrintf("timer id=%d pid=%d status=%s", id, pid, statusString(status)); + } + + std::string toString(nsecs_t now) const { + uint32_t ms = nanoseconds_to_milliseconds(now - scheduled); + return StringPrintf("timer id=%d pid=%d status=%s scheduled=%ums", + id, pid, statusString(status), -ms); + } + + static int maxId() { + return idGen; + } + + private: + // Get the next free ID. NOTIMER is never returned. + static timer_id_t nextId() { + timer_id_t id = idGen.fetch_add(1); + while (id == NOTIMER) { + id = idGen.fetch_add(1); + } + return id; + } + + // IDs start at 1. A zero ID is invalid. + static std::atomic<timer_id_t> idGen; +}; + +// IDs start at 1. +std::atomic<AnrTimerService::timer_id_t> AnrTimerService::Timer::idGen(1); + +/** + * Manage a set of timers and notify clients when there is a timeout. + */ +class AnrTimerService::Ticker { + private: + struct Entry { + const nsecs_t scheduled; + const timer_id_t id; + AnrTimerService* const service; + + Entry(nsecs_t scheduled, timer_id_t id, AnrTimerService* service) : + scheduled(scheduled), id(id), service(service) {}; + + bool operator<(const Entry &r) const { + return scheduled == r.scheduled ? id < r.id : scheduled < r.scheduled; + } + }; + + public: + + // Construct the ticker. This creates the timerfd file descriptor and starts the monitor + // thread. The monitor thread is given a unique name. + Ticker() { + timerFd_ = timer_create(); + if (timerFd_ < 0) { + ALOGE("failed to create timerFd: %s", strerror(errno)); + return; + } + + if (pthread_create(&watcher_, 0, run, this) != 0) { + ALOGE("failed to start thread: %s", strerror(errno)); + watcher_ = 0; + ::close(timerFd_); + return; + } + + // 16 is a magic number from the kernel. Thread names may not be longer than this many + // bytes, including the terminating null. The snprintf() method will truncate properly. + char name[16]; + snprintf(name, sizeof(name), "AnrTimerService"); + pthread_setname_np(watcher_, name); + + ready_ = true; + } + + ~Ticker() { + // Closing the file descriptor will close the monitor process, if any. + if (timerFd_ >= 0) ::close(timerFd_); + timerFd_ = -1; + watcher_ = 0; + } + + // Insert a timer. Unless canceled, the timer will expire at the scheduled time. If it + // expires, the service will be notified with the id. + void insert(nsecs_t scheduled, timer_id_t id, AnrTimerService *service) { + Entry e(scheduled, id, service); + AutoMutex _l(lock_); + timer_id_t front = headTimerId(); + running_.insert(e); + if (front != headTimerId()) restartLocked(); + maxRunning_ = std::max(maxRunning_, running_.size()); + } + + // Remove a timer. The timer is identified by its scheduled timeout and id. Technically, + // the id is sufficient (because timer IDs are unique) but using the timeout is more + // efficient. + void remove(nsecs_t scheduled, timer_id_t id) { + Entry key(scheduled, id, 0); + AutoMutex _l(lock_); + timer_id_t front = headTimerId(); + auto found = running_.find(key); + if (found != running_.end()) running_.erase(found); + if (front != headTimerId()) restartLocked(); + } + + // Remove every timer associated with the service. + void remove(AnrTimerService const* service) { + AutoMutex _l(lock_); + timer_id_t front = headTimerId(); + for (auto i = running_.begin(); i != running_.end(); i++) { + if (i->service == service) { + running_.erase(i); + } + } + if (front != headTimerId()) restartLocked(); + } + + // Return the number of timers still running. + size_t running() const { + AutoMutex _l(lock_); + return running_.size(); + } + + // Return the high-water mark of timers running. + size_t maxRunning() const { + AutoMutex _l(lock_); + return maxRunning_; + } + + private: + + // Return the head of the running list. The lock must be held by the caller. + timer_id_t headTimerId() { + return running_.empty() ? NOTIMER : running_.cbegin()->id; + } + + // A simple wrapper that meets the requirements of pthread_create. + static void* run(void* arg) { + reinterpret_cast<Ticker*>(arg)->monitor(); + ALOGI("monitor exited"); + return 0; + } + + // Loop (almost) forever. Whenever the timerfd expires, expire as many entries as + // possible. The loop terminates when the read fails; this generally indicates that the + // file descriptor has been closed and the thread can exit. + void monitor() { + uint64_t token = 0; + while (read(timerFd_, &token, sizeof(token)) == sizeof(token)) { + // Move expired timers into the local ready list. This is done inside + // the lock. Then, outside the lock, expire them. + nsecs_t current = now(); + std::vector<Entry> ready; + { + AutoMutex _l(lock_); + while (!running_.empty()) { + Entry timer = *(running_.begin()); + if (timer.scheduled <= current) { + ready.push_back(timer); + running_.erase(running_.cbegin()); + } else { + break; + } + } + restartLocked(); + } + // Call the notifiers outside the lock. Calling the notifiers with the lock held + // can lead to deadlock, if the Java-side handler also takes a lock. Note that the + // timerfd is already running. + for (auto i = ready.begin(); i != ready.end(); i++) { + Entry e = *i; + e.service->expire(e.id); + } + } + } + + // Restart the ticker. The caller must be holding the lock. This method updates the + // timerFd_ to expire at the time of the first Entry in the running list. This method does + // not check to see if the currently programmed expiration time is different from the + // scheduled expiration time of the first entry. + void restartLocked() { + if (!running_.empty()) { + Entry const x = *(running_.cbegin()); + nsecs_t delay = x.scheduled - now(); + // Force a minimum timeout of 10ns. + if (delay < 10) delay = 10; + time_t sec = nanoseconds_to_seconds(delay); + time_t ns = delay - seconds_to_nanoseconds(sec); + struct itimerspec setting = { + .it_interval = { 0, 0 }, + .it_value = { sec, ns }, + }; + timer_settime(timerFd_, 0, &setting, nullptr); + restarted_++; + ALOGI_IF(DEBUG, "restarted timerfd for %ld.%09ld", sec, ns); + } else { + const struct itimerspec setting = { + .it_interval = { 0, 0 }, + .it_value = { 0, 0 }, + }; + timer_settime(timerFd_, 0, &setting, nullptr); + drained_++; + ALOGI_IF(DEBUG, "drained timer list"); + } + } + + // The usual lock. + mutable Mutex lock_; + + // True if the object was initialized properly. Android does not support throwing C++ + // exceptions, so clients should check this flag after constructing the object. This is + // effectively const after the instance has been created. + bool ready_ = false; + + // The file descriptor of the timer. + int timerFd_ = -1; + + // The thread that monitors the timer. + pthread_t watcher_ = 0; + + // The number of times the timer was restarted. + size_t restarted_ = 0; + + // The number of times the timer list was exhausted. + size_t drained_ = 0; + + // The highwater mark of timers that are running. + size_t maxRunning_ = 0; + + // The list of timers that are scheduled. This set is sorted by timeout and then by timer + // ID. A set is sufficient (as opposed to a multiset) because timer IDs are unique. + std::set<Entry> running_; +}; + + +AnrTimerService::AnrTimerService(char const* label, + notifier_t notifier, void* cookie, jweak jtimer, Ticker* ticker) : + label_(label), + notifier_(notifier), + notifierCookie_(cookie), + notifierObject_(jtimer), + ticker_(ticker) { + + // Zero the statistics + maxActive_ = 0; + memset(&counters_, 0, sizeof(counters_)); + + ALOGI_IF(DEBUG, "initialized %s", label); +} + +AnrTimerService::~AnrTimerService() { + AutoMutex _l(lock_); + ticker_->remove(this); +} + +char const *AnrTimerService::statusString(Status s) { + switch (s) { + case Invalid: return "invalid"; + case Running: return "running"; + case Expired: return "expired"; + case Canceled: return "canceled"; + } + return "unknown"; +} + +AnrTimerService::timer_id_t AnrTimerService::start(int pid, int uid, + nsecs_t timeout, bool extend) { + ALOGI_IF(DEBUG, "starting"); + AutoMutex _l(lock_); + Timer t(pid, uid, timeout, extend); + insert(t); + counters_.started++; + + ALOGI_IF(DEBUG, "started timer %u timeout=%zu", t.id, static_cast<size_t>(timeout)); + return t.id; +} + +bool AnrTimerService::cancel(timer_id_t timerId) { + ALOGI_IF(DEBUG, "canceling %u", timerId); + if (timerId == NOTIMER) return false; + AutoMutex _l(lock_); + Timer timer = remove(timerId); + + bool result = timer.status == Running; + if (timer.status != Invalid) { + timer.cancel(); + } else { + counters_.error++; + } + counters_.canceled++; + ALOGI_IF(DEBUG, "canceled timer %u", timerId); + return result; +} + +bool AnrTimerService::accept(timer_id_t timerId) { + ALOGI_IF(DEBUG, "accepting %u", timerId); + if (timerId == NOTIMER) return false; + AutoMutex _l(lock_); + Timer timer = remove(timerId); + + bool result = timer.status == Expired; + if (timer.status == Expired) { + timer.accept(); + } else { + counters_.error++; + } + counters_.accepted++; + ALOGI_IF(DEBUG, "accepted timer %u", timerId); + return result; +} + +bool AnrTimerService::discard(timer_id_t timerId) { + ALOGI_IF(DEBUG, "discarding %u", timerId); + if (timerId == NOTIMER) return false; + AutoMutex _l(lock_); + Timer timer = remove(timerId); + + bool result = timer.status == Expired; + if (timer.status == Expired) { + timer.discard(); + } else { + counters_.error++; + } + counters_.discarded++; + ALOGI_IF(DEBUG, "discarded timer %u", timerId); + return result; +} + +// Hold the lock in order to manage the running list. +// the listener. +void AnrTimerService::expire(timer_id_t timerId) { + ALOGI_IF(DEBUG, "expiring %u", timerId); + // Save the timer attributes for the notification + int pid = 0; + int uid = 0; + bool expired = false; + { + AutoMutex _l(lock_); + Timer t = remove(timerId); + expired = t.expire(); + if (t.status == Invalid) { + ALOGW_IF(DEBUG, "error: expired invalid timer %u", timerId); + return; + } else { + // The timer is either Running (because it was extended) or expired (and is awaiting an + // accept or discard). + insert(t); + } + } + + // Deliver the notification outside of the lock. + if (expired) { + if (!notifier_(timerId, pid, uid, notifierCookie_, notifierObject_)) { + AutoMutex _l(lock_); + // Notification failed, which means the listener will never call accept() or + // discard(). Do not reinsert the timer. + remove(timerId); + } + } + ALOGI_IF(DEBUG, "expired timer %u", timerId); +} + +void AnrTimerService::insert(const Timer& t) { + running_.insert(t); + if (t.status == Running) { + // Only forward running timers to the ticker. Expired timers are handled separately. + ticker_->insert(t.scheduled, t.id, this); + maxActive_ = std::max(maxActive_, running_.size()); + } +} + +AnrTimerService::Timer AnrTimerService::remove(timer_id_t timerId) { + Timer key(timerId); + auto found = running_.find(key); + if (found != running_.end()) { + Timer result = *found; + running_.erase(found); + ticker_->remove(result.scheduled, result.id); + return result; + } + return Timer(); +} + +void AnrTimerService::dump(bool verbose) const { + AutoMutex _l(lock_); + ALOGI("timer %s ops started=%zu canceled=%zu accepted=%zu discarded=%zu expired=%zu", + label_.c_str(), + counters_.started, counters_.canceled, counters_.accepted, + counters_.discarded, counters_.expired); + ALOGI("timer %s stats max-active=%zu/%zu running=%zu/%zu errors=%zu", + label_.c_str(), + maxActive_, ticker_->maxRunning(), running_.size(), ticker_->running(), + counters_.error); + + if (verbose) { + nsecs_t time = now(); + for (auto i = running_.begin(); i != running_.end(); i++) { + Timer t = *i; + ALOGI(" running %s", t.toString(time).c_str()); + } + } +} + +/** + * True if the native methods are supported in this process. Native methods are supported only + * if the initialization succeeds. + */ +bool nativeSupportEnabled = false; + +/** + * Singleton/globals for the anr timer. Among other things, this includes a Ticker* and a use + * count. The JNI layer creates a single Ticker for all operational AnrTimers. The Ticker is + * created when the first AnrTimer is created, and is deleted when the last AnrTimer is closed. + */ +static Mutex gAnrLock; +struct AnrArgs { + jclass clazz = NULL; + jmethodID func = NULL; + JavaVM* vm = NULL; + AnrTimerService::Ticker* ticker = nullptr; + int tickerUseCount = 0;; +}; +static AnrArgs gAnrArgs; + +// The cookie is the address of the AnrArgs object to which the notification should be sent. +static bool anrNotify(AnrTimerService::timer_id_t timerId, int pid, int uid, + void* cookie, jweak jtimer) { + AutoMutex _l(gAnrLock); + AnrArgs* target = reinterpret_cast<AnrArgs* >(cookie); + JNIEnv *env; + if (target->vm->AttachCurrentThread(&env, 0) != JNI_OK) { + ALOGE("failed to attach thread to JavaVM"); + return false; + } + jboolean r = false; + jobject timer = env->NewGlobalRef(jtimer); + if (timer != nullptr) { + r = env->CallBooleanMethod(timer, target->func, timerId, pid, uid); + env->DeleteGlobalRef(timer); + } + target->vm->DetachCurrentThread(); + return r; +} + +jboolean anrTimerSupported(JNIEnv* env, jclass) { + return nativeSupportEnabled; +} + +jlong anrTimerCreate(JNIEnv* env, jobject jtimer, jstring jname) { + if (!nativeSupportEnabled) return 0; + AutoMutex _l(gAnrLock); + if (!gAnrArgs.ticker) { + gAnrArgs.ticker = new AnrTimerService::Ticker(); + } + gAnrArgs.tickerUseCount++; + + ScopedUtfChars name(env, jname); + jobject timer = env->NewWeakGlobalRef(jtimer); + AnrTimerService* service = + new AnrTimerService(name.c_str(), anrNotify, &gAnrArgs, timer, gAnrArgs.ticker); + return reinterpret_cast<jlong>(service); +} + +AnrTimerService *toService(jlong pointer) { + return reinterpret_cast<AnrTimerService*>(pointer); +} + +jint anrTimerClose(JNIEnv* env, jclass, jlong ptr) { + if (!nativeSupportEnabled) return -1; + if (ptr == 0) return -1; + AutoMutex _l(gAnrLock); + AnrTimerService *s = toService(ptr); + env->DeleteWeakGlobalRef(s->jtimer()); + delete s; + if (--gAnrArgs.tickerUseCount <= 0) { + delete gAnrArgs.ticker; + gAnrArgs.ticker = nullptr; + } + return 0; +} + +jint anrTimerStart(JNIEnv* env, jclass, jlong ptr, + jint pid, jint uid, jlong timeout, jboolean extend) { + if (!nativeSupportEnabled) return 0; + // On the Java side, timeouts are expressed in milliseconds and must be converted to + // nanoseconds before being passed to the library code. + return toService(ptr)->start(pid, uid, milliseconds_to_nanoseconds(timeout), extend); +} + +jboolean anrTimerCancel(JNIEnv* env, jclass, jlong ptr, jint timerId) { + if (!nativeSupportEnabled) return false; + return toService(ptr)->cancel(timerId); +} + +jboolean anrTimerAccept(JNIEnv* env, jclass, jlong ptr, jint timerId) { + if (!nativeSupportEnabled) return false; + return toService(ptr)->accept(timerId); +} + +jboolean anrTimerDiscard(JNIEnv* env, jclass, jlong ptr, jint timerId) { + if (!nativeSupportEnabled) return false; + return toService(ptr)->discard(timerId); +} + +jint anrTimerDump(JNIEnv *env, jclass, jlong ptr, jboolean verbose) { + if (!nativeSupportEnabled) return -1; + toService(ptr)->dump(verbose); + return 0; +} + +static const JNINativeMethod methods[] = { + {"nativeAnrTimerSupported", "()Z", (void*) anrTimerSupported}, + {"nativeAnrTimerCreate", "(Ljava/lang/String;)J", (void*) anrTimerCreate}, + {"nativeAnrTimerClose", "(J)I", (void*) anrTimerClose}, + {"nativeAnrTimerStart", "(JIIJZ)I", (void*) anrTimerStart}, + {"nativeAnrTimerCancel", "(JI)Z", (void*) anrTimerCancel}, + {"nativeAnrTimerAccept", "(JI)Z", (void*) anrTimerAccept}, + {"nativeAnrTimerDiscard", "(JI)Z", (void*) anrTimerDiscard}, + {"nativeAnrTimerDump", "(JZ)V", (void*) anrTimerDump}, +}; + +} // anonymous namespace + +int register_android_server_utils_AnrTimer(JNIEnv* env) +{ + static const char *className = "com/android/server/utils/AnrTimer"; + jniRegisterNativeMethods(env, className, methods, NELEM(methods)); + + jclass service = FindClassOrDie(env, className); + gAnrArgs.clazz = MakeGlobalRefOrDie(env, service); + gAnrArgs.func = env->GetMethodID(gAnrArgs.clazz, "expire", "(III)Z"); + env->GetJavaVM(&gAnrArgs.vm); + + nativeSupportEnabled = NATIVE_SUPPORT; + + return 0; +} + +} // namespace android diff --git a/services/core/jni/onload.cpp b/services/core/jni/onload.cpp index 11734da5b1ac..f3158d11b9a4 100644 --- a/services/core/jni/onload.cpp +++ b/services/core/jni/onload.cpp @@ -52,6 +52,7 @@ int register_android_server_Watchdog(JNIEnv* env); int register_android_server_HardwarePropertiesManagerService(JNIEnv* env); int register_android_server_SyntheticPasswordManager(JNIEnv* env); int register_android_hardware_display_DisplayViewport(JNIEnv* env); +int register_android_server_utils_AnrTimer(JNIEnv *env); int register_android_server_am_OomConnection(JNIEnv* env); int register_android_server_am_CachedAppOptimizer(JNIEnv* env); int register_android_server_am_LowMemDetector(JNIEnv* env); @@ -113,6 +114,7 @@ extern "C" jint JNI_OnLoad(JavaVM* vm, void* /* reserved */) register_android_server_storage_AppFuse(env); register_android_server_SyntheticPasswordManager(env); register_android_hardware_display_DisplayViewport(env); + register_android_server_utils_AnrTimer(env); register_android_server_am_OomConnection(env); register_android_server_am_CachedAppOptimizer(env); register_android_server_am_LowMemDetector(env); diff --git a/services/tests/servicestests/jni/Android.bp b/services/tests/servicestests/jni/Android.bp index 174beb81d3eb..c30e4eb666b4 100644 --- a/services/tests/servicestests/jni/Android.bp +++ b/services/tests/servicestests/jni/Android.bp @@ -23,6 +23,7 @@ cc_library_shared { ":lib_cachedAppOptimizer_native", ":lib_gameManagerService_native", ":lib_oomConnection_native", + ":lib_anrTimer_native", "onload.cpp", ], @@ -55,4 +56,4 @@ cc_library_shared { "android.hardware.graphics.mapper@4.0", "android.hidl.token@1.0-utils", ], -}
\ No newline at end of file +} diff --git a/services/tests/servicestests/jni/onload.cpp b/services/tests/servicestests/jni/onload.cpp index f160b3d97367..25487c5aabbe 100644 --- a/services/tests/servicestests/jni/onload.cpp +++ b/services/tests/servicestests/jni/onload.cpp @@ -27,6 +27,7 @@ namespace android { int register_android_server_am_CachedAppOptimizer(JNIEnv* env); int register_android_server_app_GameManagerService(JNIEnv* env); int register_android_server_am_OomConnection(JNIEnv* env); +int register_android_server_utils_AnrTimer(JNIEnv *env); }; using namespace android; @@ -44,5 +45,6 @@ extern "C" jint JNI_OnLoad(JavaVM* vm, void* /* reserved */) register_android_server_am_CachedAppOptimizer(env); register_android_server_app_GameManagerService(env); register_android_server_am_OomConnection(env); + register_android_server_utils_AnrTimer(env); return JNI_VERSION_1_4; } diff --git a/services/tests/servicestests/src/com/android/server/utils/AnrTimerTest.java b/services/tests/servicestests/src/com/android/server/utils/AnrTimerTest.java index 861d14a2cf66..6c085e085f4e 100644 --- a/services/tests/servicestests/src/com/android/server/utils/AnrTimerTest.java +++ b/services/tests/servicestests/src/com/android/server/utils/AnrTimerTest.java @@ -23,17 +23,21 @@ import static org.junit.Assert.assertTrue; import android.os.Handler; import android.os.Looper; import android.os.Message; +import android.util.Log; import android.platform.test.annotations.Presubmit; import androidx.test.filters.SmallTest; import com.android.internal.annotations.GuardedBy; +import org.junit.Ignore; import org.junit.Test; import org.junit.runner.RunWith; import org.junit.runners.Parameterized; import org.junit.runners.Parameterized.Parameters; +import java.io.PrintWriter; +import java.io.StringWriter; import java.util.ArrayList; import java.util.Arrays; import java.util.Collection; @@ -45,6 +49,9 @@ import java.util.concurrent.TimeUnit; @RunWith(Parameterized.class) public class AnrTimerTest { + // A log tag. + private static final String TAG = "AnrTimerTest"; + // The commonly used message timeout key. private static final int MSG_TIMEOUT = 1; @@ -63,9 +70,7 @@ public class AnrTimerTest { } } - /** - * The test handler is a self-contained object for a single test. - */ + /** The test helper is a self-contained object for a single test. */ private static class Helper { final Object mLock = new Object(); @@ -114,7 +119,7 @@ public class AnrTimerTest { /** * Force AnrTimer to use the test parameter for the feature flag. */ - class TestInjector extends AnrTimer.Injector { + private class TestInjector extends AnrTimer.Injector { @Override boolean anrTimerServiceEnabled() { return mEnabled; @@ -124,9 +129,9 @@ public class AnrTimerTest { /** * An instrumented AnrTimer. */ - private static class TestAnrTimer extends AnrTimer<TestArg> { + private class TestAnrTimer extends AnrTimer<TestArg> { private TestAnrTimer(Handler h, int key, String tag) { - super(h, key, tag); + super(h, key, tag, false, new TestInjector()); } TestAnrTimer(Helper helper) { @@ -173,35 +178,103 @@ public class AnrTimerTest { @Test public void testSimpleTimeout() throws Exception { Helper helper = new Helper(1); - TestAnrTimer timer = new TestAnrTimer(helper); - TestArg t = new TestArg(1, 1); - timer.start(t, 10); - // Delivery is immediate but occurs on a different thread. - assertTrue(helper.await(5000)); - TestArg[] result = helper.messages(1); - validate(t, result[0]); + try (TestAnrTimer timer = new TestAnrTimer(helper)) { + // One-time check that the injector is working as expected. + assertEquals(mEnabled, timer.serviceEnabled()); + TestArg t = new TestArg(1, 1); + timer.start(t, 10); + // Delivery is immediate but occurs on a different thread. + assertTrue(helper.await(5000)); + TestArg[] result = helper.messages(1); + validate(t, result[0]); + } } /** - * Verify that if three timers are scheduled, they are delivered in time order. + * Verify that a restarted timer is delivered exactly once. The initial timer value is very + * large, to ensure it does not expire before the timer can be restarted. + */ + @Test + public void testTimerRestart() throws Exception { + Helper helper = new Helper(1); + try (TestAnrTimer timer = new TestAnrTimer(helper)) { + TestArg t = new TestArg(1, 1); + timer.start(t, 10000); + // Briefly pause. + assertFalse(helper.await(10)); + timer.start(t, 10); + // Delivery is immediate but occurs on a different thread. + assertTrue(helper.await(5000)); + TestArg[] result = helper.messages(1); + validate(t, result[0]); + } + } + + /** + * Verify that a restarted timer is delivered exactly once. The initial timer value is very + * large, to ensure it does not expire before the timer can be restarted. + */ + @Test + public void testTimerZero() throws Exception { + Helper helper = new Helper(1); + try (TestAnrTimer timer = new TestAnrTimer(helper)) { + TestArg t = new TestArg(1, 1); + timer.start(t, 0); + // Delivery is immediate but occurs on a different thread. + assertTrue(helper.await(5000)); + TestArg[] result = helper.messages(1); + validate(t, result[0]); + } + } + + /** + * Verify that if three timers are scheduled on a single AnrTimer, they are delivered in time + * order. */ @Test public void testMultipleTimers() throws Exception { // Expect three messages. Helper helper = new Helper(3); - TestAnrTimer timer = new TestAnrTimer(helper); TestArg t1 = new TestArg(1, 1); TestArg t2 = new TestArg(1, 2); TestArg t3 = new TestArg(1, 3); - timer.start(t1, 50); - timer.start(t2, 60); - timer.start(t3, 40); - // Delivery is immediate but occurs on a different thread. - assertTrue(helper.await(5000)); - TestArg[] result = helper.messages(3); - validate(t3, result[0]); - validate(t1, result[1]); - validate(t2, result[2]); + try (TestAnrTimer timer = new TestAnrTimer(helper)) { + timer.start(t1, 50); + timer.start(t2, 60); + timer.start(t3, 40); + // Delivery is immediate but occurs on a different thread. + assertTrue(helper.await(5000)); + TestArg[] result = helper.messages(3); + validate(t3, result[0]); + validate(t1, result[1]); + validate(t2, result[2]); + } + } + + /** + * Verify that if three timers are scheduled on three separate AnrTimers, they are delivered + * in time order. + */ + @Test + public void testMultipleServices() throws Exception { + // Expect three messages. + Helper helper = new Helper(3); + TestArg t1 = new TestArg(1, 1); + TestArg t2 = new TestArg(1, 2); + TestArg t3 = new TestArg(1, 3); + try (TestAnrTimer x1 = new TestAnrTimer(helper); + TestAnrTimer x2 = new TestAnrTimer(helper); + TestAnrTimer x3 = new TestAnrTimer(helper)) { + x1.start(t1, 50); + x2.start(t2, 60); + x3.start(t3, 40); + // Delivery is immediate but occurs on a different thread. + assertTrue(helper.await(5000)); + TestArg[] result = helper.messages(3); + validate(t3, result[0]); + validate(t1, result[1]); + validate(t2, result[2]); + } } /** @@ -211,20 +284,109 @@ public class AnrTimerTest { public void testCancelTimer() throws Exception { // Expect two messages. Helper helper = new Helper(2); - TestAnrTimer timer = new TestAnrTimer(helper); TestArg t1 = new TestArg(1, 1); TestArg t2 = new TestArg(1, 2); TestArg t3 = new TestArg(1, 3); - timer.start(t1, 50); - timer.start(t2, 60); - timer.start(t3, 40); - // Briefly pause. - assertFalse(helper.await(10)); - timer.cancel(t1); - // Delivery is immediate but occurs on a different thread. - assertTrue(helper.await(5000)); - TestArg[] result = helper.messages(2); - validate(t3, result[0]); - validate(t2, result[1]); + try (TestAnrTimer timer = new TestAnrTimer(helper)) { + timer.start(t1, 50); + timer.start(t2, 60); + timer.start(t3, 40); + // Briefly pause. + assertFalse(helper.await(10)); + timer.cancel(t1); + // Delivery is immediate but occurs on a different thread. + assertTrue(helper.await(5000)); + TestArg[] result = helper.messages(2); + validate(t3, result[0]); + validate(t2, result[1]); + } + } + + /** + * Return the dump string. + */ + private String getDumpOutput() { + StringWriter sw = new StringWriter(); + PrintWriter pw = new PrintWriter(sw); + AnrTimer.dump(pw, true, new TestInjector()); + pw.close(); + return sw.getBuffer().toString(); + } + + /** + * Verify the dump output. + */ + @Test + public void testDumpOutput() throws Exception { + String r1 = getDumpOutput(); + assertEquals(false, r1.contains("timer:")); + + Helper helper = new Helper(2); + TestArg t1 = new TestArg(1, 1); + TestArg t2 = new TestArg(1, 2); + TestArg t3 = new TestArg(1, 3); + try (TestAnrTimer timer = new TestAnrTimer(helper)) { + timer.start(t1, 5000); + timer.start(t2, 5000); + timer.start(t3, 5000); + + String r2 = getDumpOutput(); + // There are timers in the list if and only if the feature is enabled. + final boolean expected = mEnabled; + assertEquals(expected, r2.contains("timer:")); + } + + String r3 = getDumpOutput(); + assertEquals(false, r3.contains("timer:")); + } + + /** + * Verify that GC works as expected. This test will almost certainly be flaky, since it + * relies on the finalizers running, which is a best-effort on the part of the JVM. + * Therefore, the test is marked @Ignore. Remove that annotation to run the test locally. + */ + @Ignore + @Test + public void testGarbageCollection() throws Exception { + if (!mEnabled) return; + + String r1 = getDumpOutput(); + assertEquals(false, r1.contains("timer:")); + + Helper helper = new Helper(2); + TestArg t1 = new TestArg(1, 1); + TestArg t2 = new TestArg(1, 2); + TestArg t3 = new TestArg(1, 3); + // The timer is explicitly not closed. It is, however, scoped to the next block. + { + TestAnrTimer timer = new TestAnrTimer(helper); + timer.start(t1, 5000); + timer.start(t2, 5000); + timer.start(t3, 5000); + + String r2 = getDumpOutput(); + // There are timers in the list if and only if the feature is enabled. + final boolean expected = mEnabled; + assertEquals(expected, r2.contains("timer:")); + } + + // Try to make finalizers run. The timer object above should be a candidate. Finalizers + // are run on their own thread, so pause this thread to give that thread some time. + String r3 = getDumpOutput(); + for (int i = 0; i < 10 && r3.contains("timer:"); i++) { + Log.i(TAG, "requesting finalization " + i); + System.gc(); + System.runFinalization(); + Thread.sleep(4 * 1000); + r3 = getDumpOutput(); + } + + // The timer was not explicitly closed but it should have been implicitly closed by GC. + assertEquals(false, r3.contains("timer:")); + } + + // TODO: [b/302724778] Remove manual JNI load + static { + System.loadLibrary("servicestestjni"); } } |