Work on issue #20401752: device idle and alarms.
Main change is to fix problems in the alarm manager where it
was not doing a good job at scheduling the device idle wakeup
before an alarm. To fix this, we now keep explicit track of
the next "wake from idle" alarm so we can consistently use that
to adjust the time of the device idle alarm if needed.
Also a bunch of debugging stuff to help further diagnose this
problem:
- Alarm summary now includes the last time the alarm went off.
- Improved dumpsys output of alarms.
- New event log tags for changes related to idle state.
Change-Id: Idd2c8d24ae23379f7c75815ddbc6835c2a04656c
diff --git a/core/java/android/app/AlarmManager.java b/core/java/android/app/AlarmManager.java
index 179957d..9d1d312 100644
--- a/core/java/android/app/AlarmManager.java
+++ b/core/java/android/app/AlarmManager.java
@@ -597,6 +597,15 @@
}
}
+ /** @hide */
+ public long getNextWakeFromIdleTime() {
+ try {
+ return mService.getNextWakeFromIdleTime();
+ } catch (RemoteException ex) {
+ return Long.MAX_VALUE;
+ }
+ }
+
/**
* Gets information about the next alarm clock currently scheduled.
*
diff --git a/core/java/android/app/IAlarmManager.aidl b/core/java/android/app/IAlarmManager.aidl
index d5719f5..327c00b 100644
--- a/core/java/android/app/IAlarmManager.aidl
+++ b/core/java/android/app/IAlarmManager.aidl
@@ -33,6 +33,7 @@
boolean setTime(long millis);
void setTimeZone(String zone);
void remove(in PendingIntent operation);
+ long getNextWakeFromIdleTime();
AlarmManager.AlarmClockInfo getNextAlarmClock(int userId);
}
diff --git a/services/core/java/com/android/server/AlarmManagerService.java b/services/core/java/com/android/server/AlarmManagerService.java
index 9f80fd8..5d02576 100644
--- a/services/core/java/com/android/server/AlarmManagerService.java
+++ b/services/core/java/com/android/server/AlarmManagerService.java
@@ -460,6 +460,7 @@
// set to null if in idle mode; while in this mode, any alarms we don't want
// to run during this time are placed in mPendingWhileIdleAlarms
Alarm mPendingIdleUntil = null;
+ Alarm mNextWakeFromIdle = null;
final ArrayList<Alarm> mPendingWhileIdleAlarms = new ArrayList<>();
public AlarmManagerService(Context context) {
@@ -583,7 +584,7 @@
final int mAlarmType;
InFlight(AlarmManagerService service, PendingIntent pendingIntent, WorkSource workSource,
- int alarmType, String tag) {
+ int alarmType, String tag, long nowELAPSED) {
mPendingIntent = pendingIntent;
mWorkSource = workSource;
mTag = tag;
@@ -593,6 +594,7 @@
fs = new FilterStats(mBroadcastStats, mTag);
mBroadcastStats.filterStats.put(mTag, fs);
}
+ fs.lastTime = nowELAPSED;
mFilterStats = fs;
mAlarmType = alarmType;
}
@@ -602,6 +604,7 @@
final BroadcastStats mBroadcastStats;
final String mTag;
+ long lastTime;
long aggregateTime;
int count;
int numWakeup;
@@ -806,33 +809,38 @@
setImplLocked(a, false, doValidate);
}
+ private void updateNextWakeFromIdleFuzzLocked() {
+ if (mNextWakeFromIdle != null) {
+
+ }
+ }
+
private void setImplLocked(Alarm a, boolean rebatching, boolean doValidate) {
if ((a.flags&AlarmManager.FLAG_IDLE_UNTIL) != 0) {
- // This is a special alarm that will put the system idle until it goes off.
+ // This is a special alarm that will put the system into idle until it goes off.
// The caller has given the time they want this to happen at, however we need
// to pull that earlier if there are existing alarms that have requested to
// bring us out of idle.
- final int N = mAlarmBatches.size();
- for (int i = 0; i < N; i++) {
- Batch b = mAlarmBatches.get(i);
- if (a.whenElapsed > b.end) {
- // There are no interesting things happening before our idle until,
- // so keep the requested time.
- break;
- }
- if ((b.flags&AlarmManager.FLAG_WAKE_FROM_IDLE) != 0) {
- a.when = a.whenElapsed = a.maxWhenElapsed = b.end;
- break;
- }
+ if (mNextWakeFromIdle != null) {
+ a.when = a.whenElapsed = a.maxWhenElapsed = mNextWakeFromIdle.whenElapsed;
}
// Add fuzz to make the alarm go off some time before the actual desired time.
final long nowElapsed = SystemClock.elapsedRealtime();
- long fuzz = fuzzForDuration(a.whenElapsed-nowElapsed);
+ final int fuzz = fuzzForDuration(a.whenElapsed-nowElapsed);
if (fuzz > 0) {
if (mRandom == null) {
mRandom = new Random();
}
- a.whenElapsed -= mRandom.nextLong() % fuzz;
+ final int delta = mRandom.nextInt(fuzz);
+ a.whenElapsed -= delta;
+ if (false) {
+ Slog.d(TAG, "Alarm when: " + a.whenElapsed);
+ Slog.d(TAG, "Delta until alarm: " + (a.whenElapsed-nowElapsed));
+ Slog.d(TAG, "Applied fuzz: " + fuzz);
+ Slog.d(TAG, "Final delta: " + delta);
+ Slog.d(TAG, "Final when: " + a.whenElapsed);
+ }
+ a.when = a.maxWhenElapsed = a.whenElapsed;
}
} else if (mPendingIdleUntil != null) {
@@ -869,11 +877,16 @@
if ((a.flags&AlarmManager.FLAG_IDLE_UNTIL) != 0) {
mPendingIdleUntil = a;
needRebatch = true;
- } else if ((a.flags&AlarmManager.FLAG_WAKE_FROM_IDLE) != 0 && mPendingIdleUntil != null) {
- // If we are adding an alarm that asks to wake from idle, and we are currently
- // idling, then we need to rebatch alarms in case the idle until time needs to
- // be updated.
- needRebatch = true;
+ } else if ((a.flags&AlarmManager.FLAG_WAKE_FROM_IDLE) != 0) {
+ if (mNextWakeFromIdle == null || mNextWakeFromIdle.whenElapsed > a.whenElapsed) {
+ mNextWakeFromIdle = a;
+ // If this wake from idle is earlier than whatever was previously scheduled,
+ // and we are currently idling, then we need to rebatch alarms in case the idle
+ // until time needs to be updated.
+ if (mPendingIdleUntil != null) {
+ needRebatch = true;
+ }
+ }
}
if (!rebatching) {
@@ -960,6 +973,11 @@
}
@Override
+ public long getNextWakeFromIdleTime() {
+ return getNextWakeFromIdleTimeImpl();
+ }
+
+ @Override
public AlarmManager.AlarmClockInfo getNextAlarmClock(int userId) {
userId = ActivityManager.handleIncomingUser(Binder.getCallingPid(),
Binder.getCallingUid(), userId, false /* allowAll */, false /* requireFull */,
@@ -1030,10 +1048,15 @@
pw.println();
pw.println("Idle mode state:");
pw.print(" Idling until: "); pw.println(mPendingIdleUntil);
- mPendingIdleUntil.dump(pw, " ", nowELAPSED, nowRTC, sdf);
+ mPendingIdleUntil.dump(pw, " ", nowRTC, nowELAPSED, sdf);
pw.println(" Pending alarms:");
dumpAlarmList(pw, mPendingWhileIdleAlarms, " ", nowELAPSED, nowRTC, sdf);
}
+ if (mNextWakeFromIdle != null) {
+ pw.println();
+ pw.print(" Next wake from idle: "); pw.println(mNextWakeFromIdle);
+ mNextWakeFromIdle.dump(pw, " ", nowRTC, nowELAPSED, sdf);
+ }
pw.println();
pw.print("Past-due non-wakeup alarms: ");
@@ -1140,7 +1163,10 @@
TimeUtils.formatDuration(fs.aggregateTime, pw);
pw.print(" "); pw.print(fs.numWakeup);
pw.print(" wakes " ); pw.print(fs.count);
- pw.print(" alarms: ");
+ pw.print(" alarms, last ");
+ TimeUtils.formatDuration(fs.lastTime, nowELAPSED, pw);
+ pw.println(":");
+ pw.print(" ");
pw.print(fs.mTag);
pw.println();
}
@@ -1216,7 +1242,13 @@
return null;
}
- private AlarmManager.AlarmClockInfo getNextAlarmClockImpl(int userId) {
+ long getNextWakeFromIdleTimeImpl() {
+ synchronized (mLock) {
+ return mNextWakeFromIdle != null ? mNextWakeFromIdle.whenElapsed : Long.MAX_VALUE;
+ }
+ }
+
+ AlarmManager.AlarmClockInfo getNextAlarmClockImpl(int userId) {
synchronized (mLock) {
return mNextAlarmClockForUser.get(userId);
}
@@ -1398,6 +1430,9 @@
mPendingIdleUntil = null;
restorePending = true;
}
+ if (mNextWakeFromIdle != null && mNextWakeFromIdle.operation.equals(operation)) {
+ mNextWakeFromIdle = null;
+ }
rebatchAllAlarmsLocked(true);
if (restorePending) {
restorePendingWhileIdleAlarmsLocked();
@@ -1585,11 +1620,19 @@
Alarm alarm = batch.get(i);
alarm.count = 1;
triggerList.add(alarm);
+ if ((alarm.flags&AlarmManager.FLAG_WAKE_FROM_IDLE) != 0) {
+ EventLogTags.writeDeviceIdleWakeFromIdle(mPendingIdleUntil != null ? 1 : 0,
+ alarm.tag);
+ }
if (mPendingIdleUntil == alarm) {
mPendingIdleUntil = null;
rebatchAllAlarmsLocked(false);
restorePendingWhileIdleAlarmsLocked();
}
+ if (mNextWakeFromIdle == alarm) {
+ mNextWakeFromIdle = null;
+ rebatchAllAlarmsLocked(false);
+ }
// Recurring alarms may have passed several alarm intervals while the
// phone was asleep or off, so pass a trigger count when sending them.
@@ -1655,7 +1698,7 @@
public final long origWhen;
public final boolean wakeup;
public final PendingIntent operation;
- public final String tag;
+ public final String tag;
public final WorkSource workSource;
public final int flags;
public int count;
@@ -1725,6 +1768,12 @@
pw.print(" repeatInterval="); pw.print(repeatInterval);
pw.print(" count="); pw.print(count);
pw.print(" flags=0x"); pw.println(Integer.toHexString(flags));
+ if (alarmClock != null) {
+ pw.print(prefix); pw.println("Alarm clock:");
+ pw.print(prefix); pw.print(" triggerTime=");
+ pw.println(sdf.format(new Date(alarmClock.getTriggerTime())));
+ pw.print(prefix); pw.print(" showIntent="); pw.println(alarmClock.getShowIntent());
+ }
pw.print(prefix); pw.print("operation="); pw.println(operation);
}
}
@@ -1762,11 +1811,11 @@
}
}
- static long fuzzForDuration(long duration) {
+ static int fuzzForDuration(long duration) {
if (duration < 15*60*1000) {
// If the duration until the time is less than 15 minutes, the maximum fuzz
// is the duration.
- return duration;
+ return (int)duration;
} else if (duration < 90*60*1000) {
// If duration is less than 1 1/2 hours, the maximum fuzz is 15 minutes,
return 15*60*1000;
@@ -1824,7 +1873,7 @@
mWakeLock.acquire();
}
final InFlight inflight = new InFlight(AlarmManagerService.this,
- alarm.operation, alarm.workSource, alarm.type, alarm.tag);
+ alarm.operation, alarm.workSource, alarm.type, alarm.tag, nowELAPSED);
mInFlight.add(inflight);
mBroadcastRefCount++;
diff --git a/services/core/java/com/android/server/EventLogTags.logtags b/services/core/java/com/android/server/EventLogTags.logtags
index 694e851..b5e648c 100644
--- a/services/core/java/com/android/server/EventLogTags.logtags
+++ b/services/core/java/com/android/server/EventLogTags.logtags
@@ -173,6 +173,13 @@
# ---------------------------
33000 wp_wallpaper_crashed (component|3)
+# ---------------------------
+# Device idle
+# ---------------------------
+34000 device_idle (state|1|5), (reason|3)
+34001 device_idle_step
+34002 device_idle_wake_from_idle (is_idle|1|5), (reason|3)
+
# ---------------------------
# ConnectivityService.java
diff --git a/services/core/java/com/android/server/power/DeviceIdleController.java b/services/core/java/com/android/server/power/DeviceIdleController.java
index a23a87b..6b29b9a 100644
--- a/services/core/java/com/android/server/power/DeviceIdleController.java
+++ b/services/core/java/com/android/server/power/DeviceIdleController.java
@@ -41,6 +41,7 @@
import com.android.internal.app.IBatteryStats;
import com.android.server.SystemService;
import com.android.server.am.BatteryStatsService;
+import com.android.server.EventLogTags;
import java.io.FileDescriptor;
import java.io.PrintWriter;
@@ -100,6 +101,11 @@
* Scaling factor to apply to current idle timeout each time we cycle through that state.
*/
private static final float DEFAULT_IDLE_FACTOR = 2f;
+ /**
+ * This is the minimum time we will allow until the next upcoming alarm for us to
+ * actually go in to idle mode.
+ */
+ private static final long DEFAULT_MIN_TIME_TO_ALARM = 60*60*1000L;
private AlarmManager mAlarmManager;
private IBatteryStats mBatteryStats;
@@ -239,7 +245,7 @@
becomeInactiveIfAppropriateLocked();
} else if (screenOn) {
mScreenOn = true;
- becomeActiveLocked();
+ becomeActiveLocked("screen");
}
}
@@ -249,12 +255,13 @@
becomeInactiveIfAppropriateLocked();
} else if (charging) {
mCharging = charging;
- becomeActiveLocked();
+ becomeActiveLocked("charging");
}
}
- void becomeActiveLocked() {
+ void becomeActiveLocked(String reason) {
if (mState != STATE_ACTIVE) {
+ EventLogTags.writeDeviceIdle(STATE_ACTIVE, reason);
mLocalPowerManager.setDeviceIdleMode(false);
try {
mNetworkPolicyManager.setDeviceIdleMode(false);
@@ -281,10 +288,22 @@
mNextIdlePendingDelay = 0;
mNextIdleDelay = 0;
scheduleAlarmLocked(mInactiveTimeout, false);
+ EventLogTags.writeDeviceIdle(mState, "no activity");
}
}
void stepIdleStateLocked() {
+ EventLogTags.writeDeviceIdleStep();
+
+ final long now = SystemClock.elapsedRealtime();
+ if ((now+DEFAULT_MIN_TIME_TO_ALARM) > mAlarmManager.getNextWakeFromIdleTime()) {
+ // Whoops, there is an upcoming alarm. We don't actually want to go idle.
+ if (mState != STATE_ACTIVE) {
+ becomeActiveLocked("alarm");
+ }
+ return;
+ }
+
switch (mState) {
case STATE_INACTIVE:
// We have now been inactive long enough, it is time to start looking
@@ -295,6 +314,7 @@
mNextIdlePendingDelay = DEFAULT_IDLE_PENDING_TIMEOUT;
mNextIdleDelay = DEFAULT_IDLE_TIMEOUT;
mState = STATE_IDLE_PENDING;
+ EventLogTags.writeDeviceIdle(mState, "step");
break;
case STATE_IDLE_PENDING:
// We have been waiting to become idle, and now it is time! This is the
@@ -307,6 +327,7 @@
mNextIdleDelay = DEFAULT_MAX_IDLE_TIMEOUT;
}
mState = STATE_IDLE;
+ EventLogTags.writeDeviceIdle(mState, "step");
mLocalPowerManager.setDeviceIdleMode(true);
try {
mNetworkPolicyManager.setDeviceIdleMode(true);
@@ -323,6 +344,7 @@
mNextIdlePendingDelay = DEFAULT_MAX_IDLE_PENDING_TIMEOUT;
}
mState = STATE_IDLE_PENDING;
+ EventLogTags.writeDeviceIdle(mState, "step");
mLocalPowerManager.setDeviceIdleMode(false);
try {
mNetworkPolicyManager.setDeviceIdleMode(false);
@@ -352,6 +374,7 @@
}
mState = STATE_ACTIVE;
mInactiveTimeout = DEFAULT_MOTION_INACTIVE_TIMEOUT;
+ EventLogTags.writeDeviceIdle(mState, "motion");
becomeInactiveIfAppropriateLocked();
}
}