Implement LongRebootBlockingReported metric
Adds a new BlockingEntityRecord class which tracks a
component or app uid which is blocking the reboot. If a
given component/app block the reboot for a time greater than
a given threshold (default is one hour), this will be logged
to statsd with a LongRebootBlockingReported atom. This atom
may be logged multiple times if the entity continues to
block the reboot for multiple thresholds. The threshold
is configurable via DeviceConfig.
Maps of blocking components/apps are stored in RebootReadinessLogger. If
a previously blocking app/component is no longer blocking the
reboot, it will be pruned from the map.
Test: Manual. Configure DeviceConfig and test with a blocking
app and component and a threshold of 10 seconds. Note that
the correct data is written to logcat when the reboot has been
blocked for 10 seconds.
Bug: 183587376
Change-Id: Ic4769968d3dfe5a2e7cf2e49632d6551bcd98404
diff --git a/service/java/com/android/server/scheduling/RebootReadinessLogger.java b/service/java/com/android/server/scheduling/RebootReadinessLogger.java
index 74c366a..66cf210 100644
--- a/service/java/com/android/server/scheduling/RebootReadinessLogger.java
+++ b/service/java/com/android/server/scheduling/RebootReadinessLogger.java
@@ -16,11 +16,18 @@
package com.android.server.scheduling;
+import static com.android.server.scheduling.SchedulingStatsLog.LONG_REBOOT_BLOCKING_REPORTED;
+import static com.android.server.scheduling.SchedulingStatsLog.LONG_REBOOT_BLOCKING_REPORTED__REBOOT_BLOCK_REASON__APP_UID;
+import static com.android.server.scheduling.SchedulingStatsLog.LONG_REBOOT_BLOCKING_REPORTED__REBOOT_BLOCK_REASON__SYSTEM_COMPONENT;
+
import android.annotation.CurrentTimeMillisLong;
+import android.annotation.IntDef;
import android.content.ApexEnvironment;
import android.os.SystemClock;
+import android.util.ArrayMap;
import android.util.AtomicFile;
import android.util.Log;
+import android.util.SparseArray;
import com.android.internal.annotations.GuardedBy;
@@ -28,6 +35,10 @@
import java.io.FileInputStream;
import java.io.FileOutputStream;
import java.io.PrintWriter;
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+import java.util.ArrayList;
+import java.util.List;
/**
@@ -43,6 +54,12 @@
private final Object mLock = new Object();
@GuardedBy("mLock")
+ private final SparseArray<BlockingEntityRecord> mBlockingApps = new SparseArray<>();
+
+ @GuardedBy("mLock")
+ private final ArrayMap<String, BlockingEntityRecord> mBlockingComponents = new ArrayMap<>();
+
+ @GuardedBy("mLock")
private long mStartTime;
@GuardedBy("mLock")
@@ -101,7 +118,7 @@
rebootStats.setTimesBlockedBySubsystems(timesBlockedBySubsystems);
rebootStats.setTimesBlockedByAppActivity(timesBlockedByAppActivity);
try (
- FileOutputStream stream = rebootStatsFile.startWrite();
+ FileOutputStream stream = rebootStatsFile.startWrite()
) {
XmlWriter writer = new XmlWriter(new PrintWriter(stream));
XmlWriter.write(writer, rebootStats);
@@ -165,6 +182,71 @@
}
}
+ /**
+ * Tracks any components which are currently blocking the reboot. If any of the components have
+ * been blocking the reboot for longer than the given threshold, this information will be logged
+ * to SchedulingStatsLog. Any components which previously blocked the reboot but are currently
+ * not blocking the reboot will be pruned from the set of tracked components.
+ *
+ * @param blockingComponentNames list of component names which are blocking the reboot.
+ * @param thresholdMs the time a component may block the reboot for before being logged.
+ */
+ void maybeLogLongBlockingComponents(List<String> blockingComponentNames, long thresholdMs) {
+ synchronized (mLock) {
+ for (String component : blockingComponentNames) {
+ BlockingEntityRecord record = mBlockingComponents.get(component);
+ if (record == null) {
+ record = new BlockingEntityRecord(component);
+ mBlockingComponents.put(component, record);
+ }
+ record.logLongRebootBlockingIfNecessary(thresholdMs);
+ }
+
+ for (String existingRecordName : mBlockingComponents.keySet()) {
+ if (!blockingComponentNames.contains(existingRecordName)) {
+ mBlockingComponents.remove(existingRecordName);
+ }
+ }
+ }
+ }
+
+ /**
+ * Tracks any app uids which are currently blocking the reboot. If any of the apps have been
+ * blocking the reboot for longer than the given threshold, this information will be logged
+ * to SchedulingStatsLog. Any apps which previously blocked the reboot but are currently
+ * not blocking the reboot will be pruned from the set of tracked uids.
+ *
+ * @param blockingAppUids list of app uids which are blocking the reboot.
+ * @param thresholdMs the time an app may block the reboot for before being logged.
+ *
+ * TODO(b/184165442): Use IntArray instead.
+ */
+ void maybeLogLongBlockingApps(List<Integer> blockingAppUids, long thresholdMs) {
+ synchronized (mLock) {
+ for (Integer uid : blockingAppUids) {
+ BlockingEntityRecord record = mBlockingApps.get(uid);
+ if (record == null) {
+ record = new BlockingEntityRecord(uid);
+ mBlockingApps.put(uid, record);
+ }
+ record.logLongRebootBlockingIfNecessary(thresholdMs);
+ }
+
+ List<Integer> uidsToPrune = new ArrayList<>();
+ for (int i = 0; i < mBlockingApps.size(); i++) {
+ int uid = mBlockingApps.keyAt(i);
+ if (!blockingAppUids.contains(uid)) {
+ uidsToPrune.add(uid);
+ }
+ }
+
+ for (Integer uid : uidsToPrune) {
+ mBlockingApps.remove(uid);
+ }
+ }
+ }
+
+
private static AtomicFile getRebootStatsFile() {
File deDir = ApexEnvironment.getApexEnvironment(MODULE_NAME).getDeviceProtectedDataDir();
File file = new File(deDir, REBOOT_STATS_FILE);
@@ -187,4 +269,86 @@
}
}
}
+
+
+ /**
+ * Class for tracking system components or app uids which are blocking the reboot. Handles
+ * the tracking of how long an entity has blocked the reboot for, and handles the logging
+ * of LongRebootBlockingReported events to SchedulingStatsLog.
+ */
+ private static final class BlockingEntityRecord {
+
+ private final int mType;
+ private String mComponentName;
+ private int mAppUid;
+ @CurrentTimeMillisLong private long mLastMetricLoggedTime;
+
+ @Retention(RetentionPolicy.SOURCE)
+ @IntDef({
+ ENTITY_TYPE_COMPONENT,
+ ENTITY_TYPE_APP,
+ })
+ private @interface EntityType {}
+
+ private static final int ENTITY_TYPE_COMPONENT = 1;
+ private static final int ENTITY_TYPE_APP = 2;
+
+ private BlockingEntityRecord(String name) {
+ mType = ENTITY_TYPE_COMPONENT;
+ mComponentName = name;
+ mLastMetricLoggedTime = System.currentTimeMillis();
+ }
+
+ private BlockingEntityRecord(int uid) {
+ mType = ENTITY_TYPE_APP;
+ mAppUid = uid;
+ mLastMetricLoggedTime = System.currentTimeMillis();
+ }
+
+ /**
+ * Writes to SchedulingStatsLog if this entity has been blocking the reboot for longer
+ * than the given threshold. If this entity has been previously written to
+ * SchedulingStatsLog, the threshold will be compared with the time since the previous
+ * metric was recorded.
+ */
+ private void logLongRebootBlockingIfNecessary(long thresholdMs) {
+ final long now = System.currentTimeMillis();
+ if ((now - mLastMetricLoggedTime) > thresholdMs) {
+ int rebootBlockReason = mapEntityTypeToRebootBlockReason(mType);
+ SchedulingStatsLog.write(LONG_REBOOT_BLOCKING_REPORTED, rebootBlockReason,
+ mComponentName, mAppUid);
+ Log.i(TAG, "LongRebootBlockingReported "
+ + " rebootBlockReason=" + rebootBlockReasonToString(rebootBlockReason)
+ + " componentName=" + mComponentName
+ + " appUid=" + mAppUid);
+ mLastMetricLoggedTime = now;
+ }
+ }
+
+ /**
+ * Returns the reboot block reason which should be logged to SchedulingStatsLog if a given
+ * EntityType is blocking the reboot for a long time.
+ */
+ private static int mapEntityTypeToRebootBlockReason(@EntityType int type) {
+ if (type == ENTITY_TYPE_COMPONENT) {
+ return LONG_REBOOT_BLOCKING_REPORTED__REBOOT_BLOCK_REASON__SYSTEM_COMPONENT;
+ } else {
+ return LONG_REBOOT_BLOCKING_REPORTED__REBOOT_BLOCK_REASON__APP_UID;
+ }
+ }
+
+ /**
+ * Maps a reboot block reason to a readable string for logging purposes.
+ */
+ private static String rebootBlockReasonToString(int rebootBlockReason) {
+ switch (rebootBlockReason) {
+ case LONG_REBOOT_BLOCKING_REPORTED__REBOOT_BLOCK_REASON__APP_UID:
+ return "APP_UID";
+ case LONG_REBOOT_BLOCKING_REPORTED__REBOOT_BLOCK_REASON__SYSTEM_COMPONENT:
+ return "SYSTEM_COMPONENT";
+ default:
+ return "UNKNOWN";
+ }
+ }
+ }
}
diff --git a/service/java/com/android/server/scheduling/RebootReadinessManagerService.java b/service/java/com/android/server/scheduling/RebootReadinessManagerService.java
index afa5372..f464145 100644
--- a/service/java/com/android/server/scheduling/RebootReadinessManagerService.java
+++ b/service/java/com/android/server/scheduling/RebootReadinessManagerService.java
@@ -96,6 +96,8 @@
private static final String PROPERTY_DISABLE_APP_ACTIVITY_CHECK = "disable_app_activity_check";
private static final String PROPERTY_DISABLE_SUBSYSTEMS_CHECK = "disable_subsystems_check";
private static final String PROPERTY_ALARM_CLOCK_THRESHOLD_MS = "alarm_clock_threshold_ms";
+ private static final String PROPERTY_LOGGING_BLOCKING_ENTITY_THRESHOLD_MS =
+ "logging_blocking_entity_threshold_ms";
private static final long DEFAULT_POLLING_INTERVAL_WHILE_IDLE_MS = TimeUnit.MINUTES.toMillis(1);
@@ -103,6 +105,8 @@
TimeUnit.MINUTES.toMillis(5);
private static final long DEFAULT_INTERACTIVITY_THRESHOLD_MS = TimeUnit.MINUTES.toMillis(30);
private static final long DEFAULT_ALARM_CLOCK_THRESHOLD_MS = TimeUnit.MINUTES.toMillis(10);
+ private static final long DEFAULT_LOGGING_BLOCKING_ENTITY_THRESHOLD_MS =
+ TimeUnit.HOURS.toMillis(1);
@GuardedBy("mLock")
private long mActivePollingIntervalMs = DEFAULT_POLLING_INTERVAL_WHILE_ACTIVE_MS;
@@ -128,6 +132,9 @@
@GuardedBy("mLock")
private long mAlarmClockThresholdMs = DEFAULT_ALARM_CLOCK_THRESHOLD_MS;
+ @GuardedBy("mLock")
+ private long mLoggingBlockingEntityThresholdMs = DEFAULT_LOGGING_BLOCKING_ENTITY_THRESHOLD_MS;
+
// A mapping of uid to package name for uids which have called markRebootPending. Reboot
// readiness state changed broadcasts will only be sent to the values in this map.
@GuardedBy("mLock")
@@ -366,6 +373,7 @@
}
final List<IRequestRebootReadinessStatusListener> blockingCallbacks = new ArrayList<>();
+ final List<String> blockingCallbackNames = new ArrayList<>();
int i = mCallbacks.beginBroadcast();
CountDownLatch latch = new CountDownLatch(i);
while (i > 0) {
@@ -381,6 +389,7 @@
if (!isReadyToReboot && (!mDisableSubsystemsCheck
|| name.startsWith(TEST_CALLBACK_PREFIX))) {
blockingCallbacks.add(callback);
+ blockingCallbackNames.add(name);
}
latch.countDown();
}
@@ -396,6 +405,8 @@
} catch (InterruptedException ignore) {
}
mCallbacks.finishBroadcast();
+ mRebootReadinessLogger.maybeLogLongBlockingComponents(blockingCallbackNames,
+ mLoggingBlockingEntityThresholdMs);
return blockingCallbacks.size() == 0;
}
@@ -414,13 +425,16 @@
if (mActivityManager != null) {
final List<RunningServiceInfo> serviceInfos =
mActivityManager.getRunningServices(Integer.MAX_VALUE);
+ List<Integer> blockingUids = new ArrayList<>();
for (int i = 0; i < serviceInfos.size(); i++) {
RunningServiceInfo info = serviceInfos.get(i);
if (info.foreground) {
- return false;
+ blockingUids.add(info.uid);
}
}
- return true;
+ mRebootReadinessLogger.maybeLogLongBlockingApps(blockingUids,
+ mLoggingBlockingEntityThresholdMs);
+ return blockingUids.size() == 0;
}
return false;
}
@@ -485,6 +499,10 @@
mAlarmClockThresholdMs = DeviceConfig.getLong(
DeviceConfig.NAMESPACE_REBOOT_READINESS,
PROPERTY_ALARM_CLOCK_THRESHOLD_MS, DEFAULT_ALARM_CLOCK_THRESHOLD_MS);
+ mLoggingBlockingEntityThresholdMs = DeviceConfig.getLong(
+ DeviceConfig.NAMESPACE_REBOOT_READINESS,
+ PROPERTY_LOGGING_BLOCKING_ENTITY_THRESHOLD_MS,
+ DEFAULT_LOGGING_BLOCKING_ENTITY_THRESHOLD_MS);
}
}
