From c352722e8af0a5510144b5f32ea87561db553f42 Mon Sep 17 00:00:00 2001 From: Dianne Hackborn Date: Wed, 13 May 2015 14:03:20 -0700 Subject: [PATCH] Ignore small time changes in alarm manager. It turns out switching to the new kernel alarm reporting causes lots and lots of spurious flags that the clock has changed. The alarm manager would blindly trust these, thinking the world has changed on it and recomputing everything and reporting this to everyone else. This was expensive. We now verify that the time has changed sufficiently that it is worth caring about. This is basically the same algorithm that battery stats was using to avoid recording small clock changes, so we are really just pushing this down into the alarm manager and can now remove that from battery stats. Also since we are getting these so much, make use of the other information in about the wakeup that tells us if an alarm went off to avoid doing anything if it didn't. Change-Id: I6f4f4226db6eb2b38ca73860786e7cf7c9136cc3 --- .../android/internal/os/BatteryStatsImpl.java | 25 --- .../android/server/AlarmManagerService.java | 156 +++++++++++------- 2 files changed, 94 insertions(+), 87 deletions(-) diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java index 405c861a498a8..de88fe42888cf 100644 --- a/core/java/com/android/internal/os/BatteryStatsImpl.java +++ b/core/java/com/android/internal/os/BatteryStatsImpl.java @@ -302,9 +302,6 @@ public final class BatteryStatsImpl extends BatteryStats { String mStartPlatformVersion; String mEndPlatformVersion; - long mLastRecordedClockTime; - long mLastRecordedClockRealtime; - long mUptime; long mUptimeStart; long mRealtime; @@ -2329,8 +2326,6 @@ public final class BatteryStatsImpl extends BatteryStats { if (dataSize == 0) { // The history is currently empty; we need it to start with a time stamp. cur.currentTime = System.currentTimeMillis(); - mLastRecordedClockTime = cur.currentTime; - mLastRecordedClockRealtime = elapsedRealtimeMs; addHistoryBufferLocked(elapsedRealtimeMs, uptimeMs, HistoryItem.CMD_RESET, cur); } addHistoryBufferLocked(elapsedRealtimeMs, uptimeMs, HistoryItem.CMD_UPDATE, cur); @@ -2503,8 +2498,6 @@ public final class BatteryStatsImpl extends BatteryStats { mHistoryOverflow = false; mActiveHistoryStates = 0xffffffff; mActiveHistoryStates2 = 0xffffffff; - mLastRecordedClockTime = 0; - mLastRecordedClockRealtime = 0; } public void updateTimeBasesLocked(boolean unplugged, boolean screenOff, long uptime, @@ -2554,18 +2547,6 @@ public final class BatteryStatsImpl extends BatteryStats { final long currentTime = System.currentTimeMillis(); final long elapsedRealtime = SystemClock.elapsedRealtime(); final long uptime = SystemClock.uptimeMillis(); - if (isStartClockTimeValid()) { - // Has the time changed sufficiently that it is really worth recording? - if (mLastRecordedClockTime != 0) { - long expectedClockTime = mLastRecordedClockTime - + (elapsedRealtime - mLastRecordedClockRealtime); - if (currentTime >= (expectedClockTime-500) - && currentTime <= (expectedClockTime+500)) { - // Not sufficiently changed, skip! - return; - } - } - } recordCurrentTimeChangeLocked(currentTime, elapsedRealtime, uptime); if (isStartClockTimeValid()) { mStartClockTime = currentTime; @@ -7941,8 +7922,6 @@ public final class BatteryStatsImpl extends BatteryStats { boolean reset) { mRecordingHistory = true; mHistoryCur.currentTime = System.currentTimeMillis(); - mLastRecordedClockTime = mHistoryCur.currentTime; - mLastRecordedClockRealtime = elapsedRealtimeMs; addHistoryBufferLocked(elapsedRealtimeMs, uptimeMs, reset ? HistoryItem.CMD_RESET : HistoryItem.CMD_CURRENT_TIME, mHistoryCur); @@ -7956,8 +7935,6 @@ public final class BatteryStatsImpl extends BatteryStats { final long uptimeMs) { if (mRecordingHistory) { mHistoryCur.currentTime = currentTime; - mLastRecordedClockTime = currentTime; - mLastRecordedClockRealtime = elapsedRealtimeMs; addHistoryBufferLocked(elapsedRealtimeMs, uptimeMs, HistoryItem.CMD_CURRENT_TIME, mHistoryCur); mHistoryCur.currentTime = 0; @@ -7967,8 +7944,6 @@ public final class BatteryStatsImpl extends BatteryStats { private void recordShutdownLocked(final long elapsedRealtimeMs, final long uptimeMs) { if (mRecordingHistory) { mHistoryCur.currentTime = System.currentTimeMillis(); - mLastRecordedClockTime = mHistoryCur.currentTime; - mLastRecordedClockRealtime = elapsedRealtimeMs; addHistoryBufferLocked(elapsedRealtimeMs, uptimeMs, HistoryItem.CMD_SHUTDOWN, mHistoryCur); mHistoryCur.currentTime = 0; diff --git a/services/core/java/com/android/server/AlarmManagerService.java b/services/core/java/com/android/server/AlarmManagerService.java index 745c1906c46ce..ad671c697cce5 100644 --- a/services/core/java/com/android/server/AlarmManagerService.java +++ b/services/core/java/com/android/server/AlarmManagerService.java @@ -138,6 +138,8 @@ class AlarmManagerService extends SystemService { long mLastAlarmDeliveryTime; long mStartCurrentDelayTime; long mNextNonWakeupDeliveryTime; + long mLastTimeChangeClockTime; + long mLastTimeChangeRealtime; int mNumTimeChanged; private final SparseArray mNextAlarmClockForUser = @@ -1024,6 +1026,11 @@ class AlarmManagerService extends SystemService { pw.print("="); pw.print(sdf.format(new Date(nowRTC))); pw.print(" nowELAPSED="); TimeUtils.formatDuration(nowELAPSED, pw); pw.println(); + pw.print("mLastTimeChangeClockTime="); pw.print(mLastTimeChangeClockTime); + pw.print("="); pw.println(sdf.format(new Date(mLastTimeChangeClockTime))); + pw.print("mLastTimeChangeRealtime="); + TimeUtils.formatDuration(mLastTimeChangeRealtime, pw); + pw.println(); if (!mInteractive) { pw.print("Time since non-interactive: "); TimeUtils.formatDuration(nowELAPSED - mNonInteractiveStartTime, pw); @@ -1955,77 +1962,102 @@ class AlarmManagerService extends SystemService { triggerList.clear(); + final long nowRTC = System.currentTimeMillis(); + final long nowELAPSED = SystemClock.elapsedRealtime(); + if ((result & TIME_CHANGED_MASK) != 0) { - if (DEBUG_BATCH) { - Slog.v(TAG, "Time changed notification from kernel; rebatching"); - } - removeImpl(mTimeTickSender); - rebatchAllAlarms(); - mClockReceiver.scheduleTimeTickEvent(); + // The kernel can give us spurious time change notifications due to + // small adjustments it makes internally; we want to filter those out. + final long lastTimeChangeClockTime; + final long expectedClockTime; synchronized (mLock) { - mNumTimeChanged++; + lastTimeChangeClockTime = mLastTimeChangeClockTime; + expectedClockTime = lastTimeChangeClockTime + + (nowELAPSED - mLastTimeChangeRealtime); + } + if (lastTimeChangeClockTime == 0 || nowRTC < (expectedClockTime-500) + || nowRTC > (expectedClockTime+500)) { + // The change is by at least +/- 500 ms (or this is the first change), + // let's do it! + if (DEBUG_BATCH) { + Slog.v(TAG, "Time changed notification from kernel; rebatching"); + } + removeImpl(mTimeTickSender); + rebatchAllAlarms(); + mClockReceiver.scheduleTimeTickEvent(); + synchronized (mLock) { + mNumTimeChanged++; + mLastTimeChangeClockTime = nowRTC; + mLastTimeChangeRealtime = nowELAPSED; + } + Intent intent = new Intent(Intent.ACTION_TIME_CHANGED); + intent.addFlags(Intent.FLAG_RECEIVER_REPLACE_PENDING + | Intent.FLAG_RECEIVER_REGISTERED_ONLY_BEFORE_BOOT); + getContext().sendBroadcastAsUser(intent, UserHandle.ALL); + + // The world has changed on us, so we need to re-evaluate alarms + // regardless of whether the kernel has told us one went off. + result |= IS_WAKEUP_MASK; } - Intent intent = new Intent(Intent.ACTION_TIME_CHANGED); - intent.addFlags(Intent.FLAG_RECEIVER_REPLACE_PENDING - | Intent.FLAG_RECEIVER_REGISTERED_ONLY_BEFORE_BOOT); - getContext().sendBroadcastAsUser(intent, UserHandle.ALL); } - - synchronized (mLock) { - final long nowRTC = System.currentTimeMillis(); - final long nowELAPSED = SystemClock.elapsedRealtime(); - if (localLOGV) Slog.v( - TAG, "Checking for alarms... rtc=" + nowRTC - + ", elapsed=" + nowELAPSED); - if (WAKEUP_STATS) { - if ((result & IS_WAKEUP_MASK) != 0) { - long newEarliest = nowRTC - RECENT_WAKEUP_PERIOD; - int n = 0; - for (WakeupEvent event : mRecentWakeups) { - if (event.when > newEarliest) break; - n++; // number of now-stale entries at the list head - } - for (int i = 0; i < n; i++) { - mRecentWakeups.remove(); - } + if (result != TIME_CHANGED_MASK) { + // If this was anything besides just a time change, then figure what if + // anything to do about alarms. + synchronized (mLock) { + if (localLOGV) Slog.v( + TAG, "Checking for alarms... rtc=" + nowRTC + + ", elapsed=" + nowELAPSED); - recordWakeupAlarms(mAlarmBatches, nowELAPSED, nowRTC); - } - } + if (WAKEUP_STATS) { + if ((result & IS_WAKEUP_MASK) != 0) { + long newEarliest = nowRTC - RECENT_WAKEUP_PERIOD; + int n = 0; + for (WakeupEvent event : mRecentWakeups) { + if (event.when > newEarliest) break; + n++; // number of now-stale entries at the list head + } + for (int i = 0; i < n; i++) { + mRecentWakeups.remove(); + } - boolean hasWakeup = triggerAlarmsLocked(triggerList, nowELAPSED, nowRTC); - if (!hasWakeup && checkAllowNonWakeupDelayLocked(nowELAPSED)) { - // if there are no wakeup alarms and the screen is off, we can - // delay what we have so far until the future. - if (mPendingNonWakeupAlarms.size() == 0) { - mStartCurrentDelayTime = nowELAPSED; - mNextNonWakeupDeliveryTime = nowELAPSED - + ((currentNonWakeupFuzzLocked(nowELAPSED)*3)/2); - } - mPendingNonWakeupAlarms.addAll(triggerList); - mNumDelayedAlarms += triggerList.size(); - rescheduleKernelAlarmsLocked(); - updateNextAlarmClockLocked(); - } else { - // now deliver the alarm intents; if there are pending non-wakeup - // alarms, we need to merge them in to the list. note we don't - // just deliver them first because we generally want non-wakeup - // alarms delivered after wakeup alarms. - rescheduleKernelAlarmsLocked(); - updateNextAlarmClockLocked(); - if (mPendingNonWakeupAlarms.size() > 0) { - calculateDeliveryPriorities(mPendingNonWakeupAlarms); - triggerList.addAll(mPendingNonWakeupAlarms); - Collections.sort(triggerList, mAlarmDispatchComparator); - final long thisDelayTime = nowELAPSED - mStartCurrentDelayTime; - mTotalDelayTime += thisDelayTime; - if (mMaxDelayTime < thisDelayTime) { - mMaxDelayTime = thisDelayTime; + recordWakeupAlarms(mAlarmBatches, nowELAPSED, nowRTC); } - mPendingNonWakeupAlarms.clear(); } - deliverAlarmsLocked(triggerList, nowELAPSED); + + boolean hasWakeup = triggerAlarmsLocked(triggerList, nowELAPSED, nowRTC); + if (!hasWakeup && checkAllowNonWakeupDelayLocked(nowELAPSED)) { + // if there are no wakeup alarms and the screen is off, we can + // delay what we have so far until the future. + if (mPendingNonWakeupAlarms.size() == 0) { + mStartCurrentDelayTime = nowELAPSED; + mNextNonWakeupDeliveryTime = nowELAPSED + + ((currentNonWakeupFuzzLocked(nowELAPSED)*3)/2); + } + mPendingNonWakeupAlarms.addAll(triggerList); + mNumDelayedAlarms += triggerList.size(); + rescheduleKernelAlarmsLocked(); + updateNextAlarmClockLocked(); + } else { + // now deliver the alarm intents; if there are pending non-wakeup + // alarms, we need to merge them in to the list. note we don't + // just deliver them first because we generally want non-wakeup + // alarms delivered after wakeup alarms. + rescheduleKernelAlarmsLocked(); + updateNextAlarmClockLocked(); + if (mPendingNonWakeupAlarms.size() > 0) { + calculateDeliveryPriorities(mPendingNonWakeupAlarms); + triggerList.addAll(mPendingNonWakeupAlarms); + Collections.sort(triggerList, mAlarmDispatchComparator); + final long thisDelayTime = nowELAPSED - mStartCurrentDelayTime; + mTotalDelayTime += thisDelayTime; + if (mMaxDelayTime < thisDelayTime) { + mMaxDelayTime = thisDelayTime; + } + mPendingNonWakeupAlarms.clear(); + } + deliverAlarmsLocked(triggerList, nowELAPSED); + } } } }