Add reporting of long wake locks.
These appear as a new event in the battery stats history,
"longwake" in the long version and "Elw" in the checkin.
The power manager keeps track of which wake locks are held
for a long time and reports them to battery stats. Long
is currently considered 1 minute or more. Once it is long,
the start event will appear, and once if is released the
event will end.
In the case of a wake lock changing (typically its work
source changing), for purposes of this accounting this is
considering a pure release of the old state and start of
the new state... so the timer will reset back to one
minute until the wake lock is considered long. This is done
to prevent things that make lots of changes to wake lock
work sources from spamming the log.
Bug: 28753137
Change-Id: I33b6168c57a7ea6ea558273dec731704123124a5
diff --git a/core/java/android/os/BatteryStats.java b/core/java/android/os/BatteryStats.java
index 1b9e2aa..af9c99f 100644
--- a/core/java/android/os/BatteryStats.java
+++ b/core/java/android/os/BatteryStats.java
@@ -1302,9 +1302,11 @@
// Event for the UID that woke up the application processor.
// Used for wakeups coming from WiFi, modem, etc.
public static final int EVENT_WAKEUP_AP = 0x0013;
+ // Event for reporting that a specific partial wake lock has been held for a long duration.
+ public static final int EVENT_LONG_WAKE_LOCK = 0x0014;
// Number of event types.
- public static final int EVENT_COUNT = 0x0014;
+ public static final int EVENT_COUNT = 0x0015;
// Mask to extract out only the type part of the event.
public static final int EVENT_TYPE_MASK = ~(EVENT_FLAG_START|EVENT_FLAG_FINISH);
@@ -1332,6 +1334,10 @@
EVENT_TEMP_WHITELIST | EVENT_FLAG_START;
public static final int EVENT_TEMP_WHITELIST_FINISH =
EVENT_TEMP_WHITELIST | EVENT_FLAG_FINISH;
+ public static final int EVENT_LONG_WAKE_LOCK_START =
+ EVENT_LONG_WAKE_LOCK | EVENT_FLAG_START;
+ public static final int EVENT_LONG_WAKE_LOCK_FINISH =
+ EVENT_LONG_WAKE_LOCK | EVENT_FLAG_FINISH;
// For CMD_EVENT.
public int eventCode;
@@ -1996,13 +2002,13 @@
public static final String[] HISTORY_EVENT_NAMES = new String[] {
"null", "proc", "fg", "top", "sync", "wake_lock_in", "job", "user", "userfg", "conn",
"active", "pkginst", "pkgunin", "alarm", "stats", "inactive", "active", "tmpwhitelist",
- "screenwake", "wakeupap"
+ "screenwake", "wakeupap", "longwake"
};
public static final String[] HISTORY_EVENT_CHECKIN_NAMES = new String[] {
"Enl", "Epr", "Efg", "Etp", "Esy", "Ewl", "Ejb", "Eur", "Euf", "Ecn",
"Eac", "Epi", "Epu", "Eal", "Est", "Eai", "Eaa", "Etw",
- "Esw", "Ewa"
+ "Esw", "Ewa", "Elw"
};
/**
diff --git a/core/java/com/android/internal/app/IBatteryStats.aidl b/core/java/com/android/internal/app/IBatteryStats.aidl
index ca69746..5623a2c 100644
--- a/core/java/com/android/internal/app/IBatteryStats.aidl
+++ b/core/java/com/android/internal/app/IBatteryStats.aidl
@@ -79,6 +79,8 @@
String newHistoryName, int newType, boolean newUnimportantForLogging);
void noteStopWakelockFromSource(in WorkSource ws, int pid, String name, String historyName,
int type);
+ void noteLongPartialWakelockStart(String name, String historyName, int uid);
+ void noteLongPartialWakelockFinish(String name, String historyName, int uid);
void noteVibratorOn(int uid, long durationMillis);
void noteVibratorOff(int uid);
diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java
index 11c1de1..b174e33 100644
--- a/core/java/com/android/internal/os/BatteryStatsImpl.java
+++ b/core/java/com/android/internal/os/BatteryStatsImpl.java
@@ -3285,6 +3285,36 @@
}
}
+ public void noteLongPartialWakelockStart(String name, String historyName, int uid) {
+ uid = mapUid(uid);
+ final long elapsedRealtime = mClocks.elapsedRealtime();
+ final long uptime = mClocks.uptimeMillis();
+ if (historyName == null) {
+ historyName = name;
+ }
+ if (!mActiveEvents.updateState(HistoryItem.EVENT_LONG_WAKE_LOCK_START, historyName, uid,
+ 0)) {
+ return;
+ }
+ addHistoryEventLocked(elapsedRealtime, uptime, HistoryItem.EVENT_LONG_WAKE_LOCK_START,
+ historyName, uid);
+ }
+
+ public void noteLongPartialWakelockFinish(String name, String historyName, int uid) {
+ uid = mapUid(uid);
+ final long elapsedRealtime = mClocks.elapsedRealtime();
+ final long uptime = mClocks.uptimeMillis();
+ if (historyName == null) {
+ historyName = name;
+ }
+ if (!mActiveEvents.updateState(HistoryItem.EVENT_LONG_WAKE_LOCK_FINISH, historyName, uid,
+ 0)) {
+ return;
+ }
+ addHistoryEventLocked(elapsedRealtime, uptime, HistoryItem.EVENT_LONG_WAKE_LOCK_FINISH,
+ historyName, uid);
+ }
+
void aggregateLastWakeupUptimeLocked(long uptimeMs) {
if (mLastWakeupReason != null) {
long deltaUptime = uptimeMs - mLastWakeupUptimeMs;
diff --git a/services/core/java/com/android/server/am/BatteryStatsService.java b/services/core/java/com/android/server/am/BatteryStatsService.java
index 7fe29b0..ff13125 100644
--- a/services/core/java/com/android/server/am/BatteryStatsService.java
+++ b/services/core/java/com/android/server/am/BatteryStatsService.java
@@ -484,6 +484,20 @@
}
}
+ public void noteLongPartialWakelockStart(String name, String historyName, int uid) {
+ enforceCallingPermission();
+ synchronized (mStats) {
+ mStats.noteLongPartialWakelockStart(name, historyName, uid);
+ }
+ }
+
+ public void noteLongPartialWakelockFinish(String name, String historyName, int uid) {
+ enforceCallingPermission();
+ synchronized (mStats) {
+ mStats.noteLongPartialWakelockFinish(name, historyName, uid);
+ }
+ }
+
public void noteStartSensor(int uid, int sensor) {
enforceCallingPermission();
synchronized (mStats) {
diff --git a/services/core/java/com/android/server/power/Notifier.java b/services/core/java/com/android/server/power/Notifier.java
index 9ccfd67..4e9f5a2 100644
--- a/services/core/java/com/android/server/power/Notifier.java
+++ b/services/core/java/com/android/server/power/Notifier.java
@@ -194,6 +194,48 @@
}
}
+ public void onLongPartialWakeLockStart(String tag, int ownerUid, WorkSource workSource,
+ String historyTag) {
+ if (DEBUG) {
+ Slog.d(TAG, "onLongPartialWakeLockStart: ownerUid=" + ownerUid
+ + ", workSource=" + workSource);
+ }
+
+ try {
+ if (workSource != null) {
+ final int N = workSource.size();
+ for (int i=0; i<N; i++) {
+ mBatteryStats.noteLongPartialWakelockStart(tag, historyTag, workSource.get(i));
+ }
+ } else {
+ mBatteryStats.noteLongPartialWakelockStart(tag, historyTag, ownerUid);
+ }
+ } catch (RemoteException ex) {
+ // Ignore
+ }
+ }
+
+ public void onLongPartialWakeLockFinish(String tag, int ownerUid, WorkSource workSource,
+ String historyTag) {
+ if (DEBUG) {
+ Slog.d(TAG, "onLongPartialWakeLockFinish: ownerUid=" + ownerUid
+ + ", workSource=" + workSource);
+ }
+
+ try {
+ if (workSource != null) {
+ final int N = workSource.size();
+ for (int i=0; i<N; i++) {
+ mBatteryStats.noteLongPartialWakelockFinish(tag, historyTag, workSource.get(i));
+ }
+ } else {
+ mBatteryStats.noteLongPartialWakelockFinish(tag, historyTag, ownerUid);
+ }
+ } catch (RemoteException ex) {
+ // Ignore
+ }
+ }
+
/**
* Called when a wake lock is changing.
*/
diff --git a/services/core/java/com/android/server/power/PowerManagerService.java b/services/core/java/com/android/server/power/PowerManagerService.java
index 12a2d2e..2215cbb 100644
--- a/services/core/java/com/android/server/power/PowerManagerService.java
+++ b/services/core/java/com/android/server/power/PowerManagerService.java
@@ -56,6 +56,7 @@
import android.service.vr.IVrManager;
import android.service.vr.IVrStateCallbacks;
import android.util.EventLog;
+import android.util.PrintWriterPrinter;
import android.util.Slog;
import android.util.SparseIntArray;
import android.util.TimeUtils;
@@ -73,9 +74,7 @@
import com.android.server.am.BatteryStatsService;
import com.android.server.lights.Light;
import com.android.server.lights.LightsManager;
-import com.android.server.vr.VrManagerInternal;
import com.android.server.vr.VrManagerService;
-import com.android.server.vr.VrStateListener;
import libcore.util.Objects;
import java.io.FileDescriptor;
@@ -108,6 +107,8 @@
private static final int MSG_SANDMAN = 2;
// Message: Sent when the screen brightness boost expires.
private static final int MSG_SCREEN_BRIGHTNESS_BOOST_TIMEOUT = 3;
+ // Message: Polling to look for long held wake locks.
+ private static final int MSG_CHECK_FOR_LONG_WAKELOCKS = 4;
// Dirty bit: mWakeLocks changed
private static final int DIRTY_WAKE_LOCKS = 1 << 0;
@@ -159,6 +160,9 @@
// This should perhaps be a setting.
private static final int SCREEN_BRIGHTNESS_BOOST_TIMEOUT = 5 * 1000;
+ // How long a partial wake lock must be held until we consider it a long wake lock.
+ static final long MIN_LONG_WAKE_CHECK_INTERVAL = 60*1000;
+
// Power hints defined in hardware/libhardware/include/hardware/power.h.
private static final int POWER_HINT_LOW_POWER = 5;
private static final int POWER_HINT_VR_MODE = 7;
@@ -221,6 +225,15 @@
// A bitfield that summarizes the state of all active wakelocks.
private int mWakeLockSummary;
+ // Have we scheduled a message to check for long wake locks? This is when we will check.
+ private long mNotifyLongScheduled;
+
+ // Last time we checked for long wake locks.
+ private long mNotifyLongDispatched;
+
+ // The time we decided to do next long check.
+ private long mNotifyLongNextCheck;
+
// If true, instructs the display controller to wait for the proximity sensor to
// go negative before turning the screen on.
private boolean mRequestWaitForNegativeProximity;
@@ -1025,6 +1038,38 @@
mNotifier.onWakeLockAcquired(wakeLock.mFlags, wakeLock.mTag, wakeLock.mPackageName,
wakeLock.mOwnerUid, wakeLock.mOwnerPid, wakeLock.mWorkSource,
wakeLock.mHistoryTag);
+ restartNofifyLongTimerLocked(wakeLock);
+ }
+ }
+
+ private void enqueueNotifyLongMsgLocked(long time) {
+ mNotifyLongScheduled = time;
+ Message msg = mHandler.obtainMessage(MSG_CHECK_FOR_LONG_WAKELOCKS);
+ msg.setAsynchronous(true);
+ mHandler.sendMessageAtTime(msg, time);
+ }
+
+ private void restartNofifyLongTimerLocked(WakeLock wakeLock) {
+ wakeLock.mAcquireTime = SystemClock.uptimeMillis();
+ if ((wakeLock.mFlags & PowerManager.WAKE_LOCK_LEVEL_MASK)
+ == PowerManager.PARTIAL_WAKE_LOCK && mNotifyLongScheduled == 0) {
+ enqueueNotifyLongMsgLocked(wakeLock.mAcquireTime + MIN_LONG_WAKE_CHECK_INTERVAL);
+ }
+ }
+
+ private void notifyWakeLockLongStartedLocked(WakeLock wakeLock) {
+ if (mSystemReady && !wakeLock.mDisabled) {
+ wakeLock.mNotifiedLong = true;
+ mNotifier.onLongPartialWakeLockStart(wakeLock.mTag, wakeLock.mOwnerUid,
+ wakeLock.mWorkSource, wakeLock.mHistoryTag);
+ }
+ }
+
+ private void notifyWakeLockLongFinishedLocked(WakeLock wakeLock) {
+ if (wakeLock.mNotifiedLong) {
+ wakeLock.mNotifiedLong = false;
+ mNotifier.onLongPartialWakeLockFinish(wakeLock.mTag, wakeLock.mOwnerUid,
+ wakeLock.mWorkSource, wakeLock.mHistoryTag);
}
}
@@ -1034,15 +1079,23 @@
mNotifier.onWakeLockChanging(wakeLock.mFlags, wakeLock.mTag, wakeLock.mPackageName,
wakeLock.mOwnerUid, wakeLock.mOwnerPid, wakeLock.mWorkSource,
wakeLock.mHistoryTag, flags, tag, packageName, uid, pid, ws, historyTag);
+ notifyWakeLockLongFinishedLocked(wakeLock);
+ // Changing the wake lock will count as releasing the old wake lock(s) and
+ // acquiring the new ones... we do this because otherwise once a wakelock
+ // becomes long, if we just continued to treat it as long we can get in to
+ // situations where we spam battery stats with every following change to it.
+ restartNofifyLongTimerLocked(wakeLock);
}
}
private void notifyWakeLockReleasedLocked(WakeLock wakeLock) {
if (mSystemReady && wakeLock.mNotifiedAcquired) {
wakeLock.mNotifiedAcquired = false;
+ wakeLock.mAcquireTime = 0;
mNotifier.onWakeLockReleased(wakeLock.mFlags, wakeLock.mTag,
wakeLock.mPackageName, wakeLock.mOwnerUid, wakeLock.mOwnerPid,
wakeLock.mWorkSource, wakeLock.mHistoryTag);
+ notifyWakeLockLongFinishedLocked(wakeLock);
}
}
@@ -1599,6 +1652,42 @@
}
}
+ void checkForLongWakeLocks() {
+ synchronized (mLock) {
+ final long now = SystemClock.uptimeMillis();
+ mNotifyLongDispatched = now;
+ final long when = now - MIN_LONG_WAKE_CHECK_INTERVAL;
+ long nextCheckTime = Long.MAX_VALUE;
+ final int numWakeLocks = mWakeLocks.size();
+ for (int i = 0; i < numWakeLocks; i++) {
+ final WakeLock wakeLock = mWakeLocks.get(i);
+ if ((wakeLock.mFlags & PowerManager.WAKE_LOCK_LEVEL_MASK)
+ == PowerManager.PARTIAL_WAKE_LOCK) {
+ if (wakeLock.mNotifiedAcquired && !wakeLock.mNotifiedLong) {
+ if (wakeLock.mAcquireTime < when) {
+ // This wake lock has exceeded the long acquire time, report!
+ notifyWakeLockLongStartedLocked(wakeLock);
+ } else {
+ // This wake lock could still become a long one, at this time.
+ long checkTime = wakeLock.mAcquireTime + MIN_LONG_WAKE_CHECK_INTERVAL;
+ if (checkTime < nextCheckTime) {
+ nextCheckTime = checkTime;
+ }
+ }
+ }
+ }
+ }
+ mNotifyLongScheduled = 0;
+ mHandler.removeMessages(MSG_CHECK_FOR_LONG_WAKELOCKS);
+ if (nextCheckTime != Long.MAX_VALUE) {
+ mNotifyLongNextCheck = nextCheckTime;
+ enqueueNotifyLongMsgLocked(nextCheckTime);
+ } else {
+ mNotifyLongNextCheck = 0;
+ }
+ }
+ }
+
/**
* Updates the value of mUserActivitySummary to summarize the user requested
* state of the system such as whether the screen should be bright or dim.
@@ -2748,6 +2837,27 @@
pw.println(" mHalAutoSuspendModeEnabled=" + mHalAutoSuspendModeEnabled);
pw.println(" mHalInteractiveModeEnabled=" + mHalInteractiveModeEnabled);
pw.println(" mWakeLockSummary=0x" + Integer.toHexString(mWakeLockSummary));
+ pw.print(" mNotifyLongScheduled=");
+ if (mNotifyLongScheduled == 0) {
+ pw.print("(none)");
+ } else {
+ TimeUtils.formatDuration(mNotifyLongScheduled, SystemClock.uptimeMillis(), pw);
+ }
+ pw.println();
+ pw.print(" mNotifyLongDispatched=");
+ if (mNotifyLongDispatched == 0) {
+ pw.print("(none)");
+ } else {
+ TimeUtils.formatDuration(mNotifyLongDispatched, SystemClock.uptimeMillis(), pw);
+ }
+ pw.println();
+ pw.print(" mNotifyLongNextCheck=");
+ if (mNotifyLongNextCheck == 0) {
+ pw.print("(none)");
+ } else {
+ TimeUtils.formatDuration(mNotifyLongNextCheck, SystemClock.uptimeMillis(), pw);
+ }
+ pw.println();
pw.println(" mUserActivitySummary=0x" + Integer.toHexString(mUserActivitySummary));
pw.println(" mRequestWaitForNegativeProximity=" + mRequestWaitForNegativeProximity);
pw.println(" mSandmanScheduled=" + mSandmanScheduled);
@@ -2856,6 +2966,10 @@
}
pw.println();
+ pw.println("Looper state:");
+ mHandler.getLooper().dump(new PrintWriterPrinter(pw), " ");
+
+ pw.println();
pw.println("Wake Locks: size=" + mWakeLocks.size());
for (WakeLock wl : mWakeLocks) {
pw.println(" " + wl);
@@ -2984,6 +3098,9 @@
case MSG_SCREEN_BRIGHTNESS_BOOST_TIMEOUT:
handleScreenBrightnessBoostTimeout();
break;
+ case MSG_CHECK_FOR_LONG_WAKELOCKS:
+ checkForLongWakeLocks();
+ break;
}
}
}
@@ -3000,7 +3117,9 @@
public String mHistoryTag;
public final int mOwnerUid;
public final int mOwnerPid;
+ public long mAcquireTime;
public boolean mNotifiedAcquired;
+ public boolean mNotifiedLong;
public boolean mDisabled;
public WakeLock(IBinder lock, int flags, String tag, String packageName,
@@ -3059,9 +3178,34 @@
@Override
public String toString() {
- return getLockLevelString()
- + " '" + mTag + "'" + getLockFlagsString() + (mDisabled ? " DISABLED" : "")
- + " (uid=" + mOwnerUid + ", pid=" + mOwnerPid + ", ws=" + mWorkSource + ")";
+ StringBuilder sb = new StringBuilder();
+ sb.append(getLockLevelString());
+ sb.append(" '");
+ sb.append(mTag);
+ sb.append("'");
+ sb.append(getLockFlagsString());
+ if (mDisabled) {
+ sb.append(" DISABLED");
+ }
+ if (mNotifiedAcquired) {
+ sb.append(" ACQ=");
+ TimeUtils.formatDuration(mAcquireTime-SystemClock.uptimeMillis(), sb);
+ }
+ if (mNotifiedLong) {
+ sb.append(" LONG");
+ }
+ sb.append(" (uid=");
+ sb.append(mOwnerUid);
+ if (mOwnerPid != 0) {
+ sb.append(" pid=");
+ sb.append(mOwnerPid);
+ }
+ if (mWorkSource != null) {
+ sb.append(" ws=");
+ sb.append(mWorkSource);
+ }
+ sb.append(")");
+ return sb.toString();
}
@SuppressWarnings("deprecation")
