Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Add half watchdogs to dropbox and make the watchdog timeout configurable."

Browse Source
This commit is contained in:
Olivier Gaillard
2022-02-07 12:05:41 +00:00
committed by Android (Google) Code Review
parent 8ffeeb86fd 6fe4769529
commit 1051bbbd1f
4 changed files with 262 additions and 121 deletions
Download Patch File Download Diff File Expand all files Collapse all files

10
core/java/android/provider/Settings.java
View File

@@ -16815,6 +16815,16 @@ public final class Settings {
public static final String LOW_POWER_STANDBY_ACTIVE_DURING_MAINTENANCE =
"low_power_standby_active_during_maintenance";
/**
* Timeout for the system server watchdog.
*
* @see {@link com.android.server.Watchdog}.
*
* @hide
*/
public static final String WATCHDOG_TIMEOUT_MILLIS =
"system_server_watchdog_timeout_ms";
/**
* Settings migrated from Wear OS settings provider.
* @hide

1
packages/SettingsProvider/test/src/android/provider/SettingsBackupTest.java
View File

@@ -594,6 +594,7 @@ public class SettingsBackupTest {
Settings.Global.APP_INTEGRITY_VERIFICATION_TIMEOUT,
Settings.Global.KEY_CHORD_POWER_VOLUME_UP,
Settings.Global.CLOCKWORK_HOME_READY,
Settings.Global.WATCHDOG_TIMEOUT_MILLIS,
Settings.Global.Wearable.BATTERY_SAVER_MODE,
Settings.Global.Wearable.COMBINED_LOCATION_ENABLED,
Settings.Global.Wearable.HAS_PAY_TOKENS,

368
services/core/java/com/android/server/Watchdog.java
View File

@@ -16,12 +16,17 @@
package com.android.server;
import static com.android.server.Watchdog.HandlerCheckerAndTimeout.withCustomTimeout;
import static com.android.server.Watchdog.HandlerCheckerAndTimeout.withDefaultTimeout;
import android.app.IActivityController;
import android.content.BroadcastReceiver;
import android.content.Context;
import android.content.Intent;
import android.content.IntentFilter;
import android.database.ContentObserver;
import android.hidl.manager.V1_0.IServiceManager;
import android.net.Uri;
import android.os.Binder;
import android.os.Build;
import android.os.Debug;
@@ -35,12 +40,15 @@ import android.os.ServiceDebugInfo;
import android.os.ServiceManager;
import android.os.SystemClock;
import android.os.SystemProperties;
import android.os.UserHandle;
import android.provider.Settings;
import android.sysprop.WatchdogProperties;
import android.util.EventLog;
import android.util.Log;
import android.util.Slog;
import android.util.SparseArray;
import com.android.internal.os.BackgroundThread;
import com.android.internal.os.ProcessCpuTracker;
import com.android.internal.os.ZygoteConnectionConstants;
import com.android.internal.util.FrameworkStatsLog;
@@ -61,10 +69,13 @@ import java.util.Arrays;
import java.util.Collections;
import java.util.HashSet;
import java.util.List;
import java.util.Optional;
import java.util.UUID;
import java.util.concurrent.TimeUnit;
/** This class calls its monitor every minute. Killing this process if they don't return **/
/**
* This class calls its monitor every minute. Killing this process if they don't return
**/
public class Watchdog {
static final String TAG = "Watchdog";
@@ -79,9 +90,7 @@ public class Watchdog {
// can trigger the watchdog.
// Note 2: The debug value is already below the wait time in ZygoteConnection. Wrapped
// applications may not work with a debug build. CTS will fail.
private static final long DEFAULT_TIMEOUT =
(DB ? 10 * 1000 : 60 * 1000) * Build.HW_TIMEOUT_MULTIPLIER;
private static final long CHECK_INTERVAL = DEFAULT_TIMEOUT / 2;
private static final long DEFAULT_TIMEOUT = DB ? 10 * 1000 : 60 * 1000;
// These are temporally ordered: larger values as lateness increases
private static final int COMPLETED = 0;
@@ -156,34 +165,71 @@ public class Watchdog {
private final Object mLock = new Object();
/* This handler will be used to post message back onto the main thread */
private final ArrayList<HandlerChecker> mHandlerCheckers = new ArrayList<>();
private final ArrayList<HandlerCheckerAndTimeout> mHandlerCheckers = new ArrayList<>();
private final HandlerChecker mMonitorChecker;
private ActivityManagerService mActivity;
private IActivityController mController;
private boolean mAllowRestart = true;
// We start with DEFAULT_TIMEOUT. This will then be update with the timeout values from Settings
// once the settings provider is initialized.
private volatile long mWatchdogTimeoutMillis = DEFAULT_TIMEOUT;
private final List<Integer> mInterestingJavaPids = new ArrayList<>();
private final TraceErrorLogger mTraceErrorLogger;
/** Holds a checker and its timeout. */
static final class HandlerCheckerAndTimeout {
private final HandlerChecker mHandler;
private final Optional<Long> mCustomTimeoutMillis;
private HandlerCheckerAndTimeout(HandlerChecker checker, Optional<Long> timeoutMillis) {
this.mHandler = checker;
this.mCustomTimeoutMillis = timeoutMillis;
}
HandlerChecker checker() {
return mHandler;
}
/** Returns the timeout. */
Optional<Long> customTimeoutMillis() {
return mCustomTimeoutMillis;
}
/**
* Creates a checker with the default timeout. The timeout will use the default value which
* is configurable server-side.
*/
static HandlerCheckerAndTimeout withDefaultTimeout(HandlerChecker checker) {
return new HandlerCheckerAndTimeout(checker, Optional.empty());
}
/**
* Creates a checker with a custom timeout. The timeout overrides the default value and will
* always be used.
*/
static HandlerCheckerAndTimeout withCustomTimeout(
HandlerChecker checker, long timeoutMillis) {
return new HandlerCheckerAndTimeout(checker, Optional.of(timeoutMillis));
}
}
/**
* Used for checking status of handle threads and scheduling monitor callbacks.
*/
public final class HandlerChecker implements Runnable {
private final Handler mHandler;
private final String mName;
private final long mWaitMax;
private final ArrayList<Monitor> mMonitors = new ArrayList<Monitor>();
private final ArrayList<Monitor> mMonitorQueue = new ArrayList<Monitor>();
private long mWaitMax;
private boolean mCompleted;
private Monitor mCurrentMonitor;
private long mStartTime;
private int mPauseCount;
HandlerChecker(Handler handler, String name, long waitMaxMillis) {
HandlerChecker(Handler handler, String name) {
mHandler = handler;
mName = name;
mWaitMax = waitMaxMillis;
mCompleted = true;
}
@@ -193,7 +239,13 @@ public class Watchdog {
mMonitorQueue.add(monitor);
}
public void scheduleCheckLocked() {
/**
* Schedules a run on the handler thread.
*
* @param handlerCheckerTimeoutMillis the timeout to use for this run
*/
public void scheduleCheckLocked(long handlerCheckerTimeoutMillis) {
mWaitMax = handlerCheckerTimeoutMillis;
if (mCompleted) {
// Safe to update monitors in queue, Handler is not in the middle of work
mMonitors.addAll(mMonitorQueue);
@@ -222,10 +274,6 @@ public class Watchdog {
mHandler.postAtFrontOfQueue(this);
}
boolean isOverdueLocked() {
return (!mCompleted) && (SystemClock.uptimeMillis() > mStartTime + mWaitMax);
}
public int getCompletionStateLocked() {
if (mCompleted) {
return COMPLETED;
@@ -336,36 +384,37 @@ public class Watchdog {
private Watchdog() {
mThread = new Thread(this::run, "watchdog");
// Initialize handler checkers for each common thread we want to check. Note
// that we are not currently checking the background thread, since it can
// potentially hold longer running operations with no guarantees about the timeliness
// of operations there.
//
// The shared foreground thread is the main checker. It is where we
// will also dispatch monitor checks and do other work.
mMonitorChecker = new HandlerChecker(FgThread.getHandler(),
"foreground thread", DEFAULT_TIMEOUT);
mHandlerCheckers.add(mMonitorChecker);
"foreground thread");
mHandlerCheckers.add(withDefaultTimeout(mMonitorChecker));
// Add checker for main thread. We only do a quick check since there
// can be UI running on the thread.
mHandlerCheckers.add(new HandlerChecker(new Handler(Looper.getMainLooper()),
"main thread", DEFAULT_TIMEOUT));
mHandlerCheckers.add(withDefaultTimeout(
new HandlerChecker(new Handler(Looper.getMainLooper()), "main thread")));
// Add checker for shared UI thread.
mHandlerCheckers.add(new HandlerChecker(UiThread.getHandler(),
"ui thread", DEFAULT_TIMEOUT));
mHandlerCheckers.add(withDefaultTimeout(
new HandlerChecker(UiThread.getHandler(), "ui thread")));
// And also check IO thread.
mHandlerCheckers.add(new HandlerChecker(IoThread.getHandler(),
"i/o thread", DEFAULT_TIMEOUT));
mHandlerCheckers.add(withDefaultTimeout(
new HandlerChecker(IoThread.getHandler(), "i/o thread")));
// And the display thread.
mHandlerCheckers.add(new HandlerChecker(DisplayThread.getHandler(),
"display thread", DEFAULT_TIMEOUT));
mHandlerCheckers.add(withDefaultTimeout(
new HandlerChecker(DisplayThread.getHandler(), "display thread")));
// And the animation thread.
mHandlerCheckers.add(new HandlerChecker(AnimationThread.getHandler(),
"animation thread", DEFAULT_TIMEOUT));
mHandlerCheckers.add(withDefaultTimeout(
new HandlerChecker(AnimationThread.getHandler(), "animation thread")));
// And the surface animation thread.
mHandlerCheckers.add(new HandlerChecker(SurfaceAnimationThread.getHandler(),
"surface animation thread", DEFAULT_TIMEOUT));
mHandlerCheckers.add(withDefaultTimeout(
new HandlerChecker(SurfaceAnimationThread.getHandler(),
"surface animation thread")));
// Initialize monitor for Binder threads.
addMonitor(new BinderThreadMonitor());
@@ -397,6 +446,62 @@ public class Watchdog {
android.Manifest.permission.REBOOT, null);
}
private static class SettingsObserver extends ContentObserver {
private final Uri mUri = Settings.Global.getUriFor(Settings.Global.WATCHDOG_TIMEOUT_MILLIS);
private final Context mContext;
private final Watchdog mWatchdog;
SettingsObserver(Context context, Watchdog watchdog) {
super(BackgroundThread.getHandler());
mContext = context;
mWatchdog = watchdog;
// Always kick once to ensure that we match current state
onChange();
}
@Override
public void onChange(boolean selfChange, Uri uri, int userId) {
if (mUri.equals(uri)) {
onChange();
}
}
public void onChange() {
try {
mWatchdog.updateWatchdogTimeout(Settings.Global.getLong(
mContext.getContentResolver(),
Settings.Global.WATCHDOG_TIMEOUT_MILLIS, DEFAULT_TIMEOUT));
} catch (RuntimeException e) {
Slog.e(TAG, "Exception while reading settings " + e.getMessage(), e);
}
}
}
/**
* Register an observer to listen to settings.
*
* It needs to be called after the settings service is initialized.
*/
public void registerSettingsObserver(Context context) {
context.getContentResolver().registerContentObserver(
Settings.Global.getUriFor(Settings.Global.WATCHDOG_TIMEOUT_MILLIS),
false,
new SettingsObserver(context, this),
UserHandle.USER_SYSTEM);
}
/**
* Updates watchdog timeout values.
*/
void updateWatchdogTimeout(long timeoutMillis) {
// See the notes on DEFAULT_TIMEOUT.
if (!DB && timeoutMillis <= ZygoteConnectionConstants.WRAPPED_PID_TIMEOUT_MILLIS) {
timeoutMillis = ZygoteConnectionConstants.WRAPPED_PID_TIMEOUT_MILLIS + 1;
}
mWatchdogTimeoutMillis = timeoutMillis;
Slog.i(TAG, "Watchdog timeout updated to " + mWatchdogTimeoutMillis + " millis");
}
private static boolean isInterestingJavaProcess(String processName) {
return processName.equals(StorageManagerService.sMediaStoreAuthorityProcessName)
|| processName.equals("com.android.phone");
@@ -446,13 +551,17 @@ public class Watchdog {
}
public void addThread(Handler thread) {
addThread(thread, DEFAULT_TIMEOUT);
synchronized (mLock) {
final String name = thread.getLooper().getThread().getName();
mHandlerCheckers.add(withDefaultTimeout(new HandlerChecker(thread, name)));
}
}
public void addThread(Handler thread, long timeoutMillis) {
synchronized (mLock) {
final String name = thread.getLooper().getThread().getName();
mHandlerCheckers.add(new HandlerChecker(thread, name, timeoutMillis));
mHandlerCheckers.add(
withCustomTimeout(new HandlerChecker(thread, name), timeoutMillis));
}
}
@@ -471,9 +580,10 @@ public class Watchdog {
*/
public void pauseWatchingCurrentThread(String reason) {
synchronized (mLock) {
for (HandlerChecker hc : mHandlerCheckers) {
if (Thread.currentThread().equals(hc.getThread())) {
hc.pauseLocked(reason);
for (HandlerCheckerAndTimeout hc : mHandlerCheckers) {
HandlerChecker checker = hc.checker();
if (Thread.currentThread().equals(checker.getThread())) {
checker.pauseLocked(reason);
}
}
}
@@ -493,9 +603,10 @@ public class Watchdog {
*/
public void resumeWatchingCurrentThread(String reason) {
synchronized (mLock) {
for (HandlerChecker hc : mHandlerCheckers) {
if (Thread.currentThread().equals(hc.getThread())) {
hc.resumeLocked(reason);
for (HandlerCheckerAndTimeout hc : mHandlerCheckers) {
HandlerChecker checker = hc.checker();
if (Thread.currentThread().equals(checker.getThread())) {
checker.resumeLocked(reason);
}
}
}
@@ -516,17 +627,17 @@ public class Watchdog {
private int evaluateCheckerCompletionLocked() {
int state = COMPLETED;
for (int i=0; i<mHandlerCheckers.size(); i++) {
HandlerChecker hc = mHandlerCheckers.get(i);
HandlerChecker hc = mHandlerCheckers.get(i).checker();
state = Math.max(state, hc.getCompletionStateLocked());
}
return state;
}
private ArrayList<HandlerChecker> getBlockedCheckersLocked() {
private ArrayList<HandlerChecker> getCheckersWithStateLocked(int completionState) {
ArrayList<HandlerChecker> checkers = new ArrayList<HandlerChecker>();
for (int i=0; i<mHandlerCheckers.size(); i++) {
HandlerChecker hc = mHandlerCheckers.get(i);
if (hc.isOverdueLocked()) {
HandlerChecker hc = mHandlerCheckers.get(i).checker();
if (hc.getCompletionStateLocked() == completionState) {
checkers.add(hc);
}
}
@@ -595,20 +706,28 @@ public class Watchdog {
private void run() {
boolean waitedHalf = false;
while (true) {
List<HandlerChecker> blockedCheckers = Collections.emptyList();
String subject = "";
boolean allowRestart = true;
int debuggerWasConnected = 0;
boolean doWaitedHalfDump = false;
// The value of mWatchdogTimeoutMillis might change while we are executing the loop.
// We store the current value to use a consistent value for all handlers.
final long watchdogTimeoutMillis = mWatchdogTimeoutMillis;
final long checkIntervalMillis = watchdogTimeoutMillis / 2;
final ArrayList<Integer> pids;
synchronized (mLock) {
long timeout = CHECK_INTERVAL;
long timeout = checkIntervalMillis;
// Make sure we (re)spin the checkers that have become idle within
// this wait-and-check interval
for (int i=0; i<mHandlerCheckers.size(); i++) {
HandlerChecker hc = mHandlerCheckers.get(i);
hc.scheduleCheckLocked();
HandlerCheckerAndTimeout hc = mHandlerCheckers.get(i);
// We pick the watchdog to apply every time we reschedule the checkers. The
// default timeout might have changed since the last run.
hc.checker().scheduleCheckLocked(hc.customTimeoutMillis()
.orElse(watchdogTimeoutMillis * Build.HW_TIMEOUT_MULTIPLIER));
}
if (debuggerWasConnected > 0) {
@@ -633,7 +752,7 @@ public class Watchdog {
if (Debug.isDebuggerConnected()) {
debuggerWasConnected = 2;
}
timeout = CHECK_INTERVAL - (SystemClock.uptimeMillis() - start);
timeout = checkIntervalMillis - (SystemClock.uptimeMillis() - start);
}
final int waitState = evaluateCheckerCompletionLocked();
@@ -649,6 +768,8 @@ public class Watchdog {
Slog.i(TAG, "WAITED_HALF");
waitedHalf = true;
// We've waited half, but we'd need to do the stack trace dump w/o the lock.
blockedCheckers = getCheckersWithStateLocked(WAITED_HALF);
subject = describeCheckersLocked(blockedCheckers);
pids = new ArrayList<>(mInterestingJavaPids);
doWaitedHalfDump = true;
} else {
@@ -656,90 +777,27 @@ public class Watchdog {
}
} else {
// something is overdue!
blockedCheckers = getBlockedCheckersLocked();
blockedCheckers = getCheckersWithStateLocked(OVERDUE);
subject = describeCheckersLocked(blockedCheckers);
allowRestart = mAllowRestart;
pids = new ArrayList<>(mInterestingJavaPids);
}
} // END synchronized (mLock)
if (doWaitedHalfDump) {
// Get critical event log before logging the half watchdog so that it doesn't
// occur in the log.
String criticalEvents =
CriticalEventLog.getInstance().logLinesForSystemServerTraceFile();
CriticalEventLog.getInstance().logHalfWatchdog(subject);
// If we got here, that means that the system is most likely hung.
//
// First collect stack traces from all threads of the system process.
//
// Then, if we reached the full timeout, kill this process so that the system will
// restart. If we reached half of the timeout, just log some information and continue.
logWatchog(doWaitedHalfDump, subject, pids);
// We've waited half the deadlock-detection interval. Pull a stack
// trace and wait another half.
ActivityManagerService.dumpStackTraces(pids, null, null,
getInterestingNativePids(), null, subject, criticalEvents);
if (doWaitedHalfDump) {
// We have waited for only half of the timeout, we continue to wait for the duration
// of the full timeout before killing the process.
continue;
}
// If we got here, that means that the system is most likely hung.
// First collect stack traces from all threads of the system process.
// Then kill this process so that the system will restart.
EventLog.writeEvent(EventLogTags.WATCHDOG, subject);
final UUID errorId = mTraceErrorLogger.generateErrorId();
if (mTraceErrorLogger.isAddErrorIdEnabled()) {
mTraceErrorLogger.addErrorIdToTrace("system_server", errorId);
mTraceErrorLogger.addSubjectToTrace(subject, errorId);
}
// Log the atom as early as possible since it is used as a mechanism to trigger
// Perfetto. Ideally, the Perfetto trace capture should happen as close to the
// point in time when the Watchdog happens as possible.
FrameworkStatsLog.write(FrameworkStatsLog.SYSTEM_SERVER_WATCHDOG_OCCURRED, subject);
// Get critical event log before logging the watchdog so that it doesn't occur in the
// log.
String criticalEvents =
CriticalEventLog.getInstance().logLinesForSystemServerTraceFile();
CriticalEventLog.getInstance().logWatchdog(subject, errorId);
long anrTime = SystemClock.uptimeMillis();
StringBuilder report = new StringBuilder();
report.append(MemoryPressureUtil.currentPsiState());
ProcessCpuTracker processCpuTracker = new ProcessCpuTracker(false);
StringWriter tracesFileException = new StringWriter();
final File stack = ActivityManagerService.dumpStackTraces(
pids, processCpuTracker, new SparseArray<>(), getInterestingNativePids(),
tracesFileException, subject, criticalEvents);
// Give some extra time to make sure the stack traces get written.
// The system's been hanging for a minute, another second or two won't hurt much.
SystemClock.sleep(5000);
processCpuTracker.update();
report.append(processCpuTracker.printCurrentState(anrTime));
report.append(tracesFileException.getBuffer());
// Trigger the kernel to dump all blocked threads, and backtraces on all CPUs to the kernel log
doSysRq('w');
doSysRq('l');
// Try to add the error to the dropbox, but assuming that the ActivityManager
// itself may be deadlocked. (which has happened, causing this statement to
// deadlock and the watchdog as a whole to be ineffective)
Thread dropboxThread = new Thread("watchdogWriteToDropbox") {
public void run() {
// If a watched thread hangs before init() is called, we don't have a
// valid mActivity. So we can't log the error to dropbox.
if (mActivity != null) {
mActivity.addErrorToDropBox(
"watchdog", null, "system_server", null, null, null,
null, report.toString(), stack, null, null, null,
errorId);
}
}
};
dropboxThread.start();
try {
dropboxThread.join(2000); // wait up to 2 seconds for it to return.
} catch (InterruptedException ignored) {}
IActivityController controller;
synchronized (mLock) {
controller = mController;
@@ -785,6 +843,74 @@ public class Watchdog {
}
}
private void logWatchog(boolean halfWatchdog, String subject, ArrayList<Integer> pids) {
// Get critical event log before logging the half watchdog so that it doesn't
// occur in the log.
String criticalEvents =
CriticalEventLog.getInstance().logLinesForSystemServerTraceFile();
final UUID errorId = mTraceErrorLogger.generateErrorId();
if (mTraceErrorLogger.isAddErrorIdEnabled()) {
mTraceErrorLogger.addErrorIdToTrace("system_server", errorId);
mTraceErrorLogger.addSubjectToTrace(subject, errorId);
}
final String dropboxTag;
if (halfWatchdog) {
dropboxTag = "pre_watchdog";
CriticalEventLog.getInstance().logHalfWatchdog(subject);
} else {
dropboxTag = "watchdog";
CriticalEventLog.getInstance().logWatchdog(subject, errorId);
EventLog.writeEvent(EventLogTags.WATCHDOG, subject);
// Log the atom as early as possible since it is used as a mechanism to trigger
// Perfetto. Ideally, the Perfetto trace capture should happen as close to the
// point in time when the Watchdog happens as possible.
FrameworkStatsLog.write(FrameworkStatsLog.SYSTEM_SERVER_WATCHDOG_OCCURRED, subject);
}
long anrTime = SystemClock.uptimeMillis();
StringBuilder report = new StringBuilder();
report.append(MemoryPressureUtil.currentPsiState());
ProcessCpuTracker processCpuTracker = new ProcessCpuTracker(false);
StringWriter tracesFileException = new StringWriter();
final File stack = ActivityManagerService.dumpStackTraces(
pids, processCpuTracker, new SparseArray<>(), getInterestingNativePids(),
tracesFileException, subject, criticalEvents);
// Give some extra time to make sure the stack traces get written.
// The system's been hanging for a whlie, another second or two won't hurt much.
SystemClock.sleep(5000);
processCpuTracker.update();
report.append(processCpuTracker.printCurrentState(anrTime));
report.append(tracesFileException.getBuffer());
if (!halfWatchdog) {
// Trigger the kernel to dump all blocked threads, and backtraces on all CPUs to the
// kernel log
doSysRq('w');
doSysRq('l');
}
// Try to add the error to the dropbox, but assuming that the ActivityManager
// itself may be deadlocked. (which has happened, causing this statement to
// deadlock and the watchdog as a whole to be ineffective)
Thread dropboxThread = new Thread("watchdogWriteToDropbox") {
public void run() {
// If a watched thread hangs before init() is called, we don't have a
// valid mActivity. So we can't log the error to dropbox.
if (mActivity != null) {
mActivity.addErrorToDropBox(
dropboxTag, null, "system_server", null, null, null,
null, report.toString(), stack, null, null, null,
errorId);
}
}
};
dropboxThread.start();
try {
dropboxThread.join(2000); // wait up to 2 seconds for it to return.
} catch (InterruptedException ignored) { }
}
private void doSysRq(char c) {
try {
FileWriter sysrq_trigger = new FileWriter("/proc/sysrq-trigger");

4
services/java/com/android/server/SystemServer.java
View File

@@ -1504,6 +1504,10 @@ public final class SystemServer implements Dumpable {
SQLiteCompatibilityWalFlags.reset();
t.traceEnd();
t.traceBegin("UpdateWatchdogTimeout");
Watchdog.getInstance().registerSettingsObserver(context);
t.traceEnd();
// Records errors and logs, for example wtf()
// Currently this service indirectly depends on SettingsProvider so do this after
// InstallSystemProviders.