Use timeout for *dexopt* wake lock
There are reports of *dexopt* lock being held for 10+ minutes, which shouldn't
normally happen on threads that are monitored by the Watchdog. Added
logging to help detecting that.
The lock is now held with a timeout of WAKELOCK_TIMEOUT_MS. It is set to a
higher value than PM's watchdog timeout for easier reading from a timing
histogram.
Test: Manual, device boots without errors
Bug: 37756892
Change-Id: Iac569474d1c95447e08fe5e9870e4518b8d22c65
diff --git a/services/core/java/com/android/server/pm/PackageDexOptimizer.java b/services/core/java/com/android/server/pm/PackageDexOptimizer.java
index 254bc2a..7e60189 100644
--- a/services/core/java/com/android/server/pm/PackageDexOptimizer.java
+++ b/services/core/java/com/android/server/pm/PackageDexOptimizer.java
@@ -24,6 +24,7 @@
import android.os.Environment;
import android.os.FileUtils;
import android.os.PowerManager;
+import android.os.SystemClock;
import android.os.UserHandle;
import android.os.WorkSource;
import android.util.Log;
@@ -54,6 +55,7 @@
import static com.android.server.pm.InstructionSets.getAppDexInstructionSets;
import static com.android.server.pm.InstructionSets.getDexCodeInstructionSets;
+import static com.android.server.pm.PackageManagerService.WATCHDOG_TIMEOUT;
import static com.android.server.pm.PackageManagerServiceCompilerMapping.getNonProfileGuidedCompilerFilter;
import static dalvik.system.DexFile.isProfileGuidedCompilerFilter;
@@ -67,13 +69,17 @@
public static final int DEX_OPT_SKIPPED = 0;
public static final int DEX_OPT_PERFORMED = 1;
public static final int DEX_OPT_FAILED = -1;
+ // One minute over PM WATCHDOG_TIMEOUT
+ private static final long WAKELOCK_TIMEOUT_MS = WATCHDOG_TIMEOUT + 1000 * 60;
/** Special library name that skips shared libraries check during compilation. */
public static final String SKIP_SHARED_LIBRARY_CHECK = "&";
+ @GuardedBy("mInstallLock")
private final Installer mInstaller;
private final Object mInstallLock;
+ @GuardedBy("mInstallLock")
private final PowerManager.WakeLock mDexoptWakeLock;
private volatile boolean mSystemReady;
@@ -111,21 +117,12 @@
return DEX_OPT_SKIPPED;
}
synchronized (mInstallLock) {
- // During boot the system doesn't need to instantiate and obtain a wake lock.
- // PowerManager might not be ready, but that doesn't mean that we can't proceed with
- // dexopt.
- final boolean useLock = mSystemReady;
- if (useLock) {
- mDexoptWakeLock.setWorkSource(new WorkSource(pkg.applicationInfo.uid));
- mDexoptWakeLock.acquire();
- }
+ final long acquireTime = acquireWakeLockLI(pkg.applicationInfo.uid);
try {
return performDexOptLI(pkg, sharedLibraries, instructionSets, checkProfiles,
targetCompilationFilter, packageStats, isUsedByOtherApps);
} finally {
- if (useLock) {
- mDexoptWakeLock.release();
- }
+ releaseWakeLockLI(acquireTime);
}
}
}
@@ -250,26 +247,50 @@
public int dexOptSecondaryDexPath(ApplicationInfo info, String path, Set<String> isas,
String compilerFilter, boolean isUsedByOtherApps) {
synchronized (mInstallLock) {
- // During boot the system doesn't need to instantiate and obtain a wake lock.
- // PowerManager might not be ready, but that doesn't mean that we can't proceed with
- // dexopt.
- final boolean useLock = mSystemReady;
- if (useLock) {
- mDexoptWakeLock.setWorkSource(new WorkSource(info.uid));
- mDexoptWakeLock.acquire();
- }
+ final long acquireTime = acquireWakeLockLI(info.uid);
try {
return dexOptSecondaryDexPathLI(info, path, isas, compilerFilter,
isUsedByOtherApps);
} finally {
- if (useLock) {
- mDexoptWakeLock.release();
- }
+ releaseWakeLockLI(acquireTime);
}
}
}
@GuardedBy("mInstallLock")
+ private long acquireWakeLockLI(final int uid) {
+ // During boot the system doesn't need to instantiate and obtain a wake lock.
+ // PowerManager might not be ready, but that doesn't mean that we can't proceed with
+ // dexopt.
+ if (!mSystemReady) {
+ return -1;
+ }
+ mDexoptWakeLock.setWorkSource(new WorkSource(uid));
+ mDexoptWakeLock.acquire(WAKELOCK_TIMEOUT_MS);
+ return SystemClock.elapsedRealtime();
+ }
+
+ @GuardedBy("mInstallLock")
+ private void releaseWakeLockLI(final long acquireTime) {
+ if (acquireTime < 0) {
+ return;
+ }
+ try {
+ if (mDexoptWakeLock.isHeld()) {
+ mDexoptWakeLock.release();
+ }
+ final long duration = SystemClock.elapsedRealtime() - acquireTime;
+ if (duration >= WAKELOCK_TIMEOUT_MS) {
+ Slog.wtf(TAG, "WakeLock " + mDexoptWakeLock.getTag()
+ + " time out. Operation took " + duration + " ms. Thread: "
+ + Thread.currentThread().getName());
+ }
+ } catch (Exception e) {
+ Slog.wtf(TAG, "Error while releasing " + mDexoptWakeLock.getTag() + " lock", e);
+ }
+ }
+
+ @GuardedBy("mInstallLock")
private int dexOptSecondaryDexPathLI(ApplicationInfo info, String path, Set<String> isas,
String compilerFilter, boolean isUsedByOtherApps) {
compilerFilter = getRealCompilerFilter(info, compilerFilter, isUsedByOtherApps);
diff --git a/services/core/java/com/android/server/pm/PackageManagerService.java b/services/core/java/com/android/server/pm/PackageManagerService.java
index 61d83e5..8d46bc6 100644
--- a/services/core/java/com/android/server/pm/PackageManagerService.java
+++ b/services/core/java/com/android/server/pm/PackageManagerService.java
@@ -444,7 +444,7 @@
* minute but we sometimes do very lengthy I/O operations on this thread,
* such as installing multi-gigabyte applications, so ours needs to be longer.
*/
- private static final long WATCHDOG_TIMEOUT = 1000*60*10; // ten minutes
+ static final long WATCHDOG_TIMEOUT = 1000*60*10; // ten minutes
/**
* Wall-clock timeout (in milliseconds) after which we *require* that an fstrim