From f697a14b88c5a828f8d299f335e0e34570a18fb5 Mon Sep 17 00:00:00 2001 From: Kweku Adams Date: Mon, 14 Sep 2020 10:10:13 -0700 Subject: [PATCH] Throttle how frequently delay alarms are set. If there are many timing delays set within a few milliseconds of each other, TimeController can end up spamming and overwhelming AlarmManager. Since a job doesn't need to have its delay constraint updated immediately and we therefore don't need to have exact timing of every single delay alarm, we should be alright limiting how often a delay alarm can be set to go off. Bug: 167681468 Test: atest com.android.server.job.controllers.TimeControllerTest Test: atest CtsJobSchedulerTestCases Change-Id: I5d2eba00d1c47ddf81bb440dd00dae0239c91eb0 --- .../job/controllers/TimeController.java | 17 +++++-- .../job/controllers/TimeControllerTest.java | 45 +++++++++++++++++++ 2 files changed, 59 insertions(+), 3 deletions(-) diff --git a/apex/jobscheduler/service/java/com/android/server/job/controllers/TimeController.java b/apex/jobscheduler/service/java/com/android/server/job/controllers/TimeController.java index 227b8276abe11..56b97f2e57572 100644 --- a/apex/jobscheduler/service/java/com/android/server/job/controllers/TimeController.java +++ b/apex/jobscheduler/service/java/com/android/server/job/controllers/TimeController.java @@ -50,6 +50,9 @@ public final class TimeController extends StateController { private static final boolean DEBUG = JobSchedulerService.DEBUG || Log.isLoggable(TAG, Log.DEBUG); + @VisibleForTesting + static final long DELAY_COALESCE_TIME_MS = 30_000L; + /** Deadline alarm tag for logging purposes */ private final String DEADLINE_TAG = "*job.deadline*"; /** Delay alarm tag for logging purposes */ @@ -57,6 +60,7 @@ public final class TimeController extends StateController { private long mNextJobExpiredElapsedMillis; private long mNextDelayExpiredElapsedMillis; + private volatile long mLastFiredDelayExpiredElapsedMillis; private final boolean mChainedAttributionEnabled; @@ -273,7 +277,6 @@ public final class TimeController extends StateController { @VisibleForTesting void checkExpiredDelaysAndResetAlarm() { synchronized (mLock) { - final long nowElapsedMillis = sElapsedRealtimeClock.millis(); long nextDelayTime = Long.MAX_VALUE; int nextDelayUid = 0; String nextDelayPackageName = null; @@ -284,7 +287,7 @@ public final class TimeController extends StateController { if (!job.hasTimingDelayConstraint()) { continue; } - if (evaluateTimingDelayConstraint(job, nowElapsedMillis)) { + if (evaluateTimingDelayConstraint(job, sElapsedRealtimeClock.millis())) { if (canStopTrackingJobLocked(job)) { it.remove(); } @@ -356,7 +359,11 @@ public final class TimeController extends StateController { * This alarm will not wake up the phone. */ private void setDelayExpiredAlarmLocked(long alarmTimeElapsedMillis, WorkSource ws) { - alarmTimeElapsedMillis = maybeAdjustAlarmTime(alarmTimeElapsedMillis); + // To avoid spamming AlarmManager in the case where many delay times are a few milliseconds + // apart, make sure the alarm is set no earlier than DELAY_COALESCE_TIME_MS since the last + // time a delay alarm went off and that the alarm is not scheduled for the past. + alarmTimeElapsedMillis = maybeAdjustAlarmTime(Math.max(alarmTimeElapsedMillis, + mLastFiredDelayExpiredElapsedMillis + DELAY_COALESCE_TIME_MS)); if (mNextDelayExpiredElapsedMillis == alarmTimeElapsedMillis) { return; } @@ -416,6 +423,7 @@ public final class TimeController extends StateController { if (DEBUG) { Slog.d(TAG, "Delay-expired alarm fired"); } + mLastFiredDelayExpiredElapsedMillis = sElapsedRealtimeClock.millis(); checkExpiredDelaysAndResetAlarm(); } }; @@ -429,6 +437,9 @@ public final class TimeController extends StateController { pw.print("Next delay alarm in "); TimeUtils.formatDuration(mNextDelayExpiredElapsedMillis, nowElapsed, pw); pw.println(); + pw.print("Last delay alarm fired @ "); + TimeUtils.formatDuration(nowElapsed, mLastFiredDelayExpiredElapsedMillis, pw); + pw.println(); pw.print("Next deadline alarm in "); TimeUtils.formatDuration(mNextJobExpiredElapsedMillis, nowElapsed, pw); pw.println(); diff --git a/services/tests/mockingservicestests/src/com/android/server/job/controllers/TimeControllerTest.java b/services/tests/mockingservicestests/src/com/android/server/job/controllers/TimeControllerTest.java index 3614763fecabb..9d847153661f8 100644 --- a/services/tests/mockingservicestests/src/com/android/server/job/controllers/TimeControllerTest.java +++ b/services/tests/mockingservicestests/src/com/android/server/job/controllers/TimeControllerTest.java @@ -52,6 +52,7 @@ import org.junit.After; import org.junit.Before; import org.junit.Test; import org.junit.runner.RunWith; +import org.mockito.ArgumentCaptor; import org.mockito.InOrder; import org.mockito.Mock; import org.mockito.MockitoSession; @@ -631,6 +632,50 @@ public class TimeControllerTest { .set(anyInt(), anyLong(), anyLong(), anyLong(), anyString(), any(), any(), any()); } + @Test + public void testDelayAlarmSchedulingCoalescedIntervals() { + doReturn(true).when(mTimeController).wouldBeReadyWithConstraintLocked(any(), anyInt()); + + final long now = JobSchedulerService.sElapsedRealtimeClock.millis(); + + JobStatus jobLatest = createJobStatus("testDelayAlarmSchedulingCoalescedIntervals", + createJob().setMinimumLatency(HOUR_IN_MILLIS)); + JobStatus jobMiddle = createJobStatus("testDelayAlarmSchedulingCoalescedIntervals", + createJob().setMinimumLatency(TimeController.DELAY_COALESCE_TIME_MS / 2)); + JobStatus jobEarliest = createJobStatus("testDelayAlarmSchedulingCoalescedIntervals", + createJob().setMinimumLatency(TimeController.DELAY_COALESCE_TIME_MS / 10)); + + ArgumentCaptor listenerCaptor = + ArgumentCaptor.forClass(AlarmManager.OnAlarmListener.class); + InOrder inOrder = inOrder(mAlarmManager); + + mTimeController.maybeStartTrackingJobLocked(jobEarliest, null); + mTimeController.maybeStartTrackingJobLocked(jobMiddle, null); + mTimeController.maybeStartTrackingJobLocked(jobLatest, null); + inOrder.verify(mAlarmManager, times(1)) + .set(anyInt(), eq(now + TimeController.DELAY_COALESCE_TIME_MS / 10), anyLong(), + anyLong(), eq(TAG_DELAY), + listenerCaptor.capture(), any(), any()); + final AlarmManager.OnAlarmListener delayListener = listenerCaptor.getValue(); + + advanceElapsedClock(TimeController.DELAY_COALESCE_TIME_MS / 10); + delayListener.onAlarm(); + // The next delay alarm time should be TimeController.DELAY_COALESCE_TIME_MS after the last + // time the delay alarm fired. + inOrder.verify(mAlarmManager, times(1)) + .set(anyInt(), eq(now + TimeController.DELAY_COALESCE_TIME_MS / 10 + + TimeController.DELAY_COALESCE_TIME_MS), anyLong(), + anyLong(), eq(TAG_DELAY), any(), any(), any()); + + advanceElapsedClock(TimeController.DELAY_COALESCE_TIME_MS); + delayListener.onAlarm(); + // The last job is significantly after the coalesce time, so the 3rd scheduling shouldn't be + // affected by the first two jobs' alarms. + inOrder.verify(mAlarmManager, times(1)) + .set(anyInt(), eq(now + HOUR_IN_MILLIS), anyLong(), + anyLong(), eq(TAG_DELAY), any(), any(), any()); + } + @Test public void testEvaluateStateLocked_Delay() { final long now = JobSchedulerService.sElapsedRealtimeClock.millis();