diff options
| author | 2023-02-20 14:40:42 +0000 | |
|---|---|---|
| committer | 2023-02-20 17:58:48 +0000 | |
| commit | c752ab59a2ca2e097b65c221f15ebf27d4ce429a (patch) | |
| tree | c6da9889c0a9339b5a967d6caf9f7b53be1e94b8 | |
| parent | 4ada8aaf7fcee105032767951783f5f42029eec3 (diff) | |
Fix a scheduling issue
Metrics suggest that there are some cases when the
NetworkTimeUpdateService POLL intent can fire much more often than
expected. There is no hard evidence yet for what is actually happening;
this commit contains a fix for one possible answer: the sharing of the
NtpTrustedTime singleton can lead to successful refreshes producing new
cached time results that aren't being handled properly. Recent changes
made the current scheduling logic more susceptable to problems here.
This commit makes changes intended to ensure that a callback cannot be
scheduled in the past. It also explicitly resets the mTryAgainCounter to
zero if there is a recent-enough successful time refresh to avoid using
the "short" polling interval incorrectly when the latest refresh was
successful.
A test has been added that fails with old logic and passes with new
logic.
Bug: 269425914
Test: Local manual testing
Test: atest services/tests/servicestests/src/com/android/server/timedetector/NetworkTimeUpdateServiceTest.java
Change-Id: I0ae4cd94badaf25a7b951d33fc6414ea3332863e
2 files changed, 265 insertions, 93 deletions
diff --git a/services/core/java/com/android/server/timedetector/NetworkTimeUpdateService.java b/services/core/java/com/android/server/timedetector/NetworkTimeUpdateService.java index 4d1f9d597543..399e9413bded 100644 --- a/services/core/java/com/android/server/timedetector/NetworkTimeUpdateService.java +++ b/services/core/java/com/android/server/timedetector/NetworkTimeUpdateService.java @@ -65,7 +65,7 @@ import java.util.function.Supplier; * If a request fails, it retries a number of times with a "short" interval and then resets to the * normal interval. The process then repeats. * - * <p>When a valid network time is available, the time is always suggested to the {@link + * <p>When a valid network time is available, the network time is always suggested to the {@link * com.android.server.timedetector.TimeDetectorService} where it may be used to set the device * system clock, depending on user settings and what other signals are available. */ @@ -286,7 +286,7 @@ public class NetworkTimeUpdateService extends Binder { } /** - * Checks if the user prefers to automatically set the time. + * Checks if the user prefers to automatically set the device's system clock time. */ private boolean isAutomaticTimeEnabled() { ContentResolver resolver = mContext.getContentResolver(); @@ -313,7 +313,7 @@ public class NetworkTimeUpdateService extends Binder { } /** - * The interface the service uses to interact with the time refresh logic. + * The interface the service uses to interact with the network time refresh logic. * Extracted for testing. */ @VisibleForTesting @@ -387,10 +387,10 @@ public class NetworkTimeUpdateService extends Binder { private final NtpTrustedTime mNtpTrustedTime; /** - * Records the time of the last refresh attempt (successful or otherwise) by this service. - * This is used when scheduling the next refresh attempt. In cases where {@link - * #refreshAndRescheduleIfRequired} is called too frequently, this will prevent each call - * resulting in a network request. See also {@link #mShortPollingIntervalMillis}. + * Records the elapsed realtime of the last refresh attempt (successful or otherwise) by + * this service. This is used when scheduling the next refresh attempt. In cases where + * {@link #refreshAndRescheduleIfRequired} is called too frequently, this will prevent each + * call resulting in a network request. See also {@link #mShortPollingIntervalMillis}. * * <p>Time servers are a shared resource and so Android should avoid loading them. * Generally, a refresh attempt will succeed and the service won't need to make further @@ -454,8 +454,11 @@ public class NetworkTimeUpdateService extends Binder { return; } - // Attempt to refresh the network time if there is no latest time result, or if the - // latest time result is considered too old. + // Step 1: Work out if the latest time result, if any, needs to be refreshed and handle + // the refresh. + + // A refresh should be attempted if there is no latest time result, or if the latest + // time result is considered too old. NtpTrustedTime.TimeResult initialTimeResult = mNtpTrustedTime.getCachedTimeResult(); boolean shouldAttemptRefresh; synchronized (this) { @@ -472,22 +475,42 @@ public class NetworkTimeUpdateService extends Binder { boolean refreshSuccessful = false; if (shouldAttemptRefresh) { // This is a blocking call. Deliberately invoked without holding the "this" monitor - // to avoid blocking logic that wants to use the "this" monitor. + // to avoid blocking other logic that wants to use the "this" monitor, e.g. dump(). refreshSuccessful = tryRefresh(network); } synchronized (this) { - // Manage mTryAgainCounter. + // This section of code deliberately doesn't assume it is the only component using + // the NtpTrustedTime singleton to obtain NTP times: another component in the same + // process could be gathering NTP signals (which then won't have been suggested to + // the time detector). + // TODO(b/222295093): Make this class the sole user of the NtpTrustedTime singleton + // and simplify / reduce duplicate suggestions and other logic. + NtpTrustedTime.TimeResult latestTimeResult = mNtpTrustedTime.getCachedTimeResult(); + + // currentElapsedRealtimeMillis is used to evaluate ages and refresh scheduling + // below. Capturing this after obtaining the cached time result ensures that latest + // time result ages will be >= 0. + long currentElapsedRealtimeMillis = mElapsedRealtimeMillisSupplier.get(); + + long latestTimeResultAgeMillis = calculateTimeResultAgeMillis( + latestTimeResult, currentElapsedRealtimeMillis); + + // Step 2: Set mTryAgainCounter. + // + == 0: The last attempt was successful OR the latest time result is acceptable + // OR the mTryAgainCounter exceeded mTryAgainTimesMax and has been reset + // to 0. In all these cases the normal refresh interval should be used. + // + > 0: The last refresh attempt was unsuccessful. Some number of retries are + // allowed using the short interval depending on mTryAgainTimesMax. if (shouldAttemptRefresh) { if (refreshSuccessful) { - // Reset failure tracking. mTryAgainCounter = 0; } else { if (mTryAgainTimesMax < 0) { // When mTryAgainTimesMax is negative there's no enforced maximum and // short intervals should be used until a successful refresh. Setting // mTryAgainCounter to 1 is sufficient for the interval calculations - // below. There's no need to increment. + // below, i.e. there's no need to increment. mTryAgainCounter = 1; } else { mTryAgainCounter++; @@ -497,58 +520,97 @@ public class NetworkTimeUpdateService extends Binder { } } } + if (latestTimeResultAgeMillis < mNormalPollingIntervalMillis) { + // The latest time result may indicate a successful refresh has been achieved by + // another user of the NtpTrustedTime singleton. This could be an "else if", but + // this is deliberately done defensively in all cases to maintain the invariant + // that mTryAgainCounter will be 0 if the latest time result is currently ok. + mTryAgainCounter = 0; + } - // currentElapsedRealtimeMillis is used to evaluate ages and refresh scheduling - // below. Capturing this after a possible successful refresh ensures that latest - // time result ages will be >= 0. - long currentElapsedRealtimeMillis = mElapsedRealtimeMillisSupplier.get(); - - // This section of code deliberately doesn't assume it is the only component using - // mNtpTrustedTime to obtain NTP times: another component in the same process could - // be gathering NTP signals (which then won't have been suggested to the time - // detector). - // TODO(b/222295093): Make this class the sole owner of mNtpTrustedTime and - // simplify / reduce duplicate suggestions. - NtpTrustedTime.TimeResult latestTimeResult = mNtpTrustedTime.getCachedTimeResult(); - long latestTimeResultAgeMillis = calculateTimeResultAgeMillis( - latestTimeResult, currentElapsedRealtimeMillis); - - // Suggest the latest time result to the time detector if it is fresh regardless of - // whether refresh happened above. + // Step 3: Suggest the latest time result to the time detector if it is fresh + // regardless of whether a refresh happened / succeeded above. The time detector + // service can detect duplicate suggestions and not do more work than it has to, so + // there is no need to avoid making duplicate suggestions. if (latestTimeResultAgeMillis < mNormalPollingIntervalMillis) { - // We assume the time detector service will detect duplicate suggestions and not - // do more work than it has to, so no need to avoid making duplicate - // suggestions. makeNetworkTimeSuggestion(latestTimeResult, reason, refreshCallbacks); } - // (Re)schedule the next refresh based on the latest state. - // Determine which refresh delay to use by using the current value of - // mTryAgainCounter. The refresh delay is applied to a different point in time - // depending on whether the latest available time result (if any) is still - // considered fresh to ensure the delay acts correctly. - long refreshDelayMillis = mTryAgainCounter > 0 + // Step 4: (Re)schedule the next refresh attempt based on the latest state. + + // Determine which refresh attempt delay to use by using the current value of + // mTryAgainCounter. + long refreshAttemptDelayMillis = mTryAgainCounter > 0 ? mShortPollingIntervalMillis : mNormalPollingIntervalMillis; + + // The refresh attempt delay is applied to a different point in time depending on + // whether a refresh attempt is overdue to ensure the refresh attempt scheduling + // acts correctly / safely, i.e. won't schedule actions for immediate execution or + // in the past. long nextRefreshElapsedRealtimeMillis; - if (latestTimeResultAgeMillis < mNormalPollingIntervalMillis) { - // The latest time result is fresh, use it to determine when next to refresh. + if (latestTimeResultAgeMillis < refreshAttemptDelayMillis) { + // The latestTimeResultAgeMillis and refreshAttemptDelayMillis indicate a + // refresh attempt is not yet due. This branch uses the elapsed realtime of the + // latest time result to calculate when the latest time result will become too + // old and the next refresh attempt will be due. + // + // Possibilities: + // + A refresh was attempted and successful, mTryAgainCounter will be set + // to 0, refreshAttemptDelayMillis == mNormalPollingIntervalMillis, and this + // branch will execute. + // + No refresh was attempted, but something else refreshed the latest time + // result held by the NtpTrustedTime. + // + // If a refresh was attempted but was unsuccessful, latestTimeResultAgeMillis >= + // mNormalPollingIntervalMillis (because otherwise it wouldn't be attempted), + // this branch won't be executed, and the one below will be instead. nextRefreshElapsedRealtimeMillis = - latestTimeResult.getElapsedRealtimeMillis() + refreshDelayMillis; + latestTimeResult.getElapsedRealtimeMillis() + refreshAttemptDelayMillis; } else if (mLastRefreshAttemptElapsedRealtimeMillis != null) { - // The latest time result is missing or old and still needs to be refreshed. - // mLastRefreshAttemptElapsedRealtimeMillis, which should always be set by this - // point because there's no fresh time result, should be very close to - // currentElapsedRealtimeMillis unless the refresh was not allowed. + // This branch is executed when the latest time result is missing, or it's older + // than refreshAttemptDelayMillis. There may already have been attempts to + // refresh the network time that have failed, so the important point for this + // branch is not how old the latest time result is, but when the last refresh + // attempt took place: + // + If a refresh was just attempted (and failed), then + // mLastRefreshAttemptElapsedRealtimeMillis will be close to + // currentElapsedRealtimeMillis. + // + If a refresh was not just attempted, for a refresh not to have been + // attempted EITHER: + // + The latest time result must be < mNormalPollingIntervalMillis ago + // (would be handled by the branch above) + // + A refresh wasn't allowed because {time since last refresh attempt} + // < mShortPollingIntervalMillis, so + // (mLastRefreshAttemptElapsedRealtimeMillis + refreshAttemptDelayMillis) + // would have to be in the future regardless of the + // refreshAttemptDelayMillis value. This ignores the execution time + // between the "current time" used to work out whether a refresh needed to + // happen, and "current time" used to compute the last time result age, + // but a single short interval shouldn't matter. nextRefreshElapsedRealtimeMillis = - mLastRefreshAttemptElapsedRealtimeMillis + refreshDelayMillis; + mLastRefreshAttemptElapsedRealtimeMillis + refreshAttemptDelayMillis; } else { - // This should not happen: mLastRefreshAttemptElapsedRealtimeMillis should - // always be non-null by this point. - logToDebugAndDumpsys( - "mLastRefreshAttemptElapsedRealtimeMillis unexpectedly missing." - + " Scheduling using currentElapsedRealtimeMillis"); + // This branch should never execute: mLastRefreshAttemptElapsedRealtimeMillis + // should always be non-null because a refresh should always be attempted at + // least once above. Regardelss, the calculation below should result in safe + // scheduling behavior. + String logMsg = "mLastRefreshAttemptElapsedRealtimeMillis unexpectedly missing." + + " Scheduling using currentElapsedRealtimeMillis"; + Log.w(TAG, logMsg); + logToDebugAndDumpsys(logMsg); + nextRefreshElapsedRealtimeMillis = + currentElapsedRealtimeMillis + refreshAttemptDelayMillis; + } + + // Defensive coding to guard against bad scheduling / logic errors above: Try to + // ensure that alarms aren't scheduled in the past. + if (nextRefreshElapsedRealtimeMillis <= currentElapsedRealtimeMillis) { + String logMsg = "nextRefreshElapsedRealtimeMillis is a time in the past." + + " Scheduling using currentElapsedRealtimeMillis instead"; + Log.w(TAG, logMsg); + logToDebugAndDumpsys(logMsg); nextRefreshElapsedRealtimeMillis = - currentElapsedRealtimeMillis + refreshDelayMillis; + currentElapsedRealtimeMillis + refreshAttemptDelayMillis; } refreshCallbacks.scheduleNextRefresh(nextRefreshElapsedRealtimeMillis); @@ -562,7 +624,7 @@ public class NetworkTimeUpdateService extends Binder { + formatElapsedRealtimeMillis(currentElapsedRealtimeMillis) + ", latestTimeResult=" + latestTimeResult + ", mTryAgainCounter=" + mTryAgainCounter - + ", refreshDelayMillis=" + refreshDelayMillis + + ", refreshAttemptDelayMillis=" + refreshAttemptDelayMillis + ", nextRefreshElapsedRealtimeMillis=" + formatElapsedRealtimeMillis(nextRefreshElapsedRealtimeMillis)); } @@ -592,6 +654,12 @@ public class NetworkTimeUpdateService extends Binder { return currentElapsedRealtimeMillis >= nextRefreshAllowedElapsedRealtimeMillis; } + /** + * Attempts a network time refresh. Updates {@link + * #mLastRefreshAttemptElapsedRealtimeMillis} regardless of the outcome and returns whether + * the attempt was successful. The latest successful refresh result can be found in {@link + * NtpTrustedTime#getCachedTimeResult()}. + */ private boolean tryRefresh(@NonNull Network network) { long currentElapsedRealtimeMillis = mElapsedRealtimeMillisSupplier.get(); synchronized (this) { @@ -600,15 +668,18 @@ public class NetworkTimeUpdateService extends Binder { return mNtpTrustedTime.forceRefresh(network); } - /** Suggests the time to the time detector. It may choose use it to set the system clock. */ - private void makeNetworkTimeSuggestion(@NonNull TimeResult ntpResult, + /** + * Suggests the network time to the time detector. It may choose use it to set the system + * clock. + */ + private void makeNetworkTimeSuggestion(@NonNull TimeResult timeResult, @NonNull String debugInfo, @NonNull RefreshCallbacks refreshCallbacks) { UnixEpochTime timeSignal = new UnixEpochTime( - ntpResult.getElapsedRealtimeMillis(), ntpResult.getTimeMillis()); + timeResult.getElapsedRealtimeMillis(), timeResult.getTimeMillis()); NetworkTimeSuggestion timeSuggestion = - new NetworkTimeSuggestion(timeSignal, ntpResult.getUncertaintyMillis()); + new NetworkTimeSuggestion(timeSignal, timeResult.getUncertaintyMillis()); timeSuggestion.addDebugInfo(debugInfo); - timeSuggestion.addDebugInfo(ntpResult.toString()); + timeSuggestion.addDebugInfo(timeResult.toString()); refreshCallbacks.submitSuggestion(timeSuggestion); } diff --git a/services/tests/servicestests/src/com/android/server/timedetector/NetworkTimeUpdateServiceTest.java b/services/tests/servicestests/src/com/android/server/timedetector/NetworkTimeUpdateServiceTest.java index 2f431bd8a416..d91ee92e005e 100644 --- a/services/tests/servicestests/src/com/android/server/timedetector/NetworkTimeUpdateServiceTest.java +++ b/services/tests/servicestests/src/com/android/server/timedetector/NetworkTimeUpdateServiceTest.java @@ -111,12 +111,11 @@ public class NetworkTimeUpdateServiceTest { verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); // Check everything happened that was supposed to. + NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult); + verify(mockCallback).submitSuggestion(expectedSuggestion); long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( timeResult.getElapsedRealtimeMillis() + expectedDelayMillis); - - NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult); - verify(mockCallback).submitSuggestion(expectedSuggestion); } @Test @@ -148,6 +147,7 @@ public class NetworkTimeUpdateServiceTest { verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); // Check everything happened that was supposed to. + verify(mockCallback, never()).submitSuggestion(any()); long expectedDelayMillis; if (i < tryAgainTimesMax) { expectedDelayMillis = shortPollingIntervalMillis; @@ -156,7 +156,6 @@ public class NetworkTimeUpdateServiceTest { } verify(mockCallback).scheduleNextRefresh( mFakeElapsedRealtimeClock.getElapsedRealtimeMillis() + expectedDelayMillis); - verify(mockCallback, never()).submitSuggestion(any()); reset(mMockNtpTrustedTime); } @@ -196,10 +195,10 @@ public class NetworkTimeUpdateServiceTest { // initially. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( timeResult.getElapsedRealtimeMillis() + expectedDelayMillis); - verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); reset(mMockNtpTrustedTime); } @@ -222,6 +221,9 @@ public class NetworkTimeUpdateServiceTest { // Expect a refresh attempt each time as the cached network time is too old. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + // No valid time, no suggestion. + verify(mockCallback, never()).submitSuggestion(any()); + // Check the scheduling. long expectedDelayMillis; if (i < tryAgainTimesMax) { @@ -232,9 +234,6 @@ public class NetworkTimeUpdateServiceTest { verify(mockCallback).scheduleNextRefresh( mFakeElapsedRealtimeClock.getElapsedRealtimeMillis() + expectedDelayMillis); - // No valid time, no suggestion. - verify(mockCallback, never()).submitSuggestion(any()); - reset(mMockNtpTrustedTime); // Simulate the passage of time for realism. @@ -276,10 +275,10 @@ public class NetworkTimeUpdateServiceTest { // initially. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( timeResult.getElapsedRealtimeMillis() + expectedDelayMillis); - verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); reset(mMockNtpTrustedTime); } @@ -302,15 +301,14 @@ public class NetworkTimeUpdateServiceTest { // Expect a refresh attempt each time as the cached network time is too old. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); - // Check the scheduling. tryAgainTimesMax == 0, so the algorithm should start with + // No valid time, no suggestion. + verify(mockCallback, never()).submitSuggestion(any()); + // Check the scheduling. tryAgainTimesMax == 0, so the algorithm should start with long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( mFakeElapsedRealtimeClock.getElapsedRealtimeMillis() + expectedDelayMillis); - // No valid time, no suggestion. - verify(mockCallback, never()).submitSuggestion(any()); - reset(mMockNtpTrustedTime); // Simulate the passage of time for realism. @@ -352,10 +350,10 @@ public class NetworkTimeUpdateServiceTest { // initially. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( timeResult.getElapsedRealtimeMillis() + expectedDelayMillis); - verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); reset(mMockNtpTrustedTime); } @@ -378,15 +376,15 @@ public class NetworkTimeUpdateServiceTest { // Expect a refresh attempt each time as the cached network time is too old. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + // No valid time, no suggestion. + verify(mockCallback, never()).submitSuggestion(any()); + // Check the scheduling. tryAgainTimesMax == -1, so it should always be // shortPollingIntervalMillis. long expectedDelayMillis = shortPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( mFakeElapsedRealtimeClock.getElapsedRealtimeMillis() + expectedDelayMillis); - // No valid time, no suggestion. - verify(mockCallback, never()).submitSuggestion(any()); - reset(mMockNtpTrustedTime); // Simulate the passage of time for realism. @@ -426,11 +424,11 @@ public class NetworkTimeUpdateServiceTest { // initially. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult1); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( timeResult1.getElapsedRealtimeMillis() + expectedDelayMillis); - NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult1); - verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); reset(mMockNtpTrustedTime); } @@ -453,12 +451,13 @@ public class NetworkTimeUpdateServiceTest { // Expect the refresh attempt to have been made: the timeResult is too old. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + // No valid time, no suggestion. + verify(mockCallback, never()).submitSuggestion(any()); + long expectedDelayMillis = shortPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( mFakeElapsedRealtimeClock.getElapsedRealtimeMillis() + expectedDelayMillis); - // No valid time, no suggestion. - verify(mockCallback, never()).submitSuggestion(any()); reset(mMockNtpTrustedTime); } @@ -485,11 +484,11 @@ public class NetworkTimeUpdateServiceTest { // Expect the refresh attempt to have been made: the timeResult is too old. verify(mMockNtpTrustedTime).forceRefresh(mDummyNetwork); + NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult2); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( timeResult2.getElapsedRealtimeMillis() + expectedDelayMillis); - NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult2); - verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); reset(mMockNtpTrustedTime); } } @@ -525,16 +524,16 @@ public class NetworkTimeUpdateServiceTest { // Expect no refresh attempt to have been made. verify(mMockNtpTrustedTime, never()).forceRefresh(any()); + // Suggestions must be made every time if the cached time value is not too old in case it + // was refreshed by a different component. + NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); + // The next wake-up should be rescheduled for when the cached time value will become too // old. long expectedDelayMillis = normalPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( timeResult.getElapsedRealtimeMillis() + expectedDelayMillis); - - // Suggestions must be made every time if the cached time value is not too old in case it - // was refreshed by a different component. - NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult); - verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); } /** @@ -568,13 +567,13 @@ public class NetworkTimeUpdateServiceTest { // Expect a refresh attempt to have been made. verify(mMockNtpTrustedTime, times(1)).forceRefresh(mDummyNetwork); + // Suggestions should not be made if the cached time value is too old. + verify(mockCallback, never()).submitSuggestion(any()); + // The next wake-up should be rescheduled using the short polling interval. long expectedDelayMillis = shortPollingIntervalMillis; verify(mockCallback).scheduleNextRefresh( mFakeElapsedRealtimeClock.getElapsedRealtimeMillis() + expectedDelayMillis); - - // Suggestions should not be made if the cached time value is too old. - verify(mockCallback, never()).submitSuggestion(any()); } /** @@ -614,6 +613,9 @@ public class NetworkTimeUpdateServiceTest { verify(mMockNtpTrustedTime, times(1)).forceRefresh(mDummyNetwork); lastRefreshAttemptElapsedMillis = mFakeElapsedRealtimeClock.getElapsedRealtimeMillis(); + // Suggestions should not be made if the cached time value is too old. + verify(mockCallback, never()).submitSuggestion(any()); + // The next wake-up should be rescheduled using the normalPollingIntervalMillis. // Because the time signal age > normalPollingIntervalMillis, the last refresh attempt // time will be used. @@ -622,9 +624,6 @@ public class NetworkTimeUpdateServiceTest { lastRefreshAttemptElapsedMillis + expectedDelayMillis; verify(mockCallback).scheduleNextRefresh(expectedNextRefreshElapsedMillis); - // Suggestions should not be made if the cached time value is too old. - verify(mockCallback, never()).submitSuggestion(any()); - reset(mMockNtpTrustedTime); } @@ -646,6 +645,9 @@ public class NetworkTimeUpdateServiceTest { // Expect no refresh attempt to have been made: time elapsed isn't enough. verify(mMockNtpTrustedTime, never()).forceRefresh(any()); + // Suggestions should not be made if the cached time value is too old. + verify(mockCallback, never()).submitSuggestion(any()); + // The next wake-up should be rescheduled using the normal polling interval and the last // refresh attempt time. long expectedDelayMillis = normalPollingIntervalMillis; @@ -653,11 +655,110 @@ public class NetworkTimeUpdateServiceTest { lastRefreshAttemptElapsedMillis + expectedDelayMillis; verify(mockCallback).scheduleNextRefresh(expectedNextRefreshElapsedMillis); + reset(mMockNtpTrustedTime); + } + } + + /** + * Confirms that if a refreshAndRescheduleIfRequired() call is made and there was a recently + * failed refresh, then another won't be scheduled too soon. + */ + @Test + public void engineImpl_refreshAndRescheduleIfRequired_minimumRefreshTimeEnforced_b269425914() { + mFakeElapsedRealtimeClock.setElapsedRealtimeMillis(ARBITRARY_ELAPSED_REALTIME_MILLIS); + + int normalPollingIntervalMillis = 7777777; + int shortPollingIntervalMillis = 3333; + int tryAgainTimesMax = 3; + NetworkTimeUpdateService.Engine engine = new NetworkTimeUpdateService.EngineImpl( + mFakeElapsedRealtimeClock, + normalPollingIntervalMillis, shortPollingIntervalMillis, tryAgainTimesMax, + mMockNtpTrustedTime); + + NtpTrustedTime.TimeResult timeResult1; + + // Start out with a successful refresh. + long lastRefreshAttemptElapsedMillis; + { + mFakeElapsedRealtimeClock.incrementMillis(normalPollingIntervalMillis); + timeResult1 = createNtpTimeResult(mFakeElapsedRealtimeClock.getElapsedRealtimeMillis()); + when(mMockNtpTrustedTime.getCachedTimeResult()).thenReturn(null, timeResult1); + when(mMockNtpTrustedTime.forceRefresh(mDummyNetwork)).thenReturn(true); + + RefreshCallbacks mockCallback = mock(RefreshCallbacks.class); + // Trigger the engine's logic. + engine.refreshAndRescheduleIfRequired(mDummyNetwork, "Test", mockCallback); + + // Expect a refresh attempt to have been made. + verify(mMockNtpTrustedTime, times(1)).forceRefresh(mDummyNetwork); + lastRefreshAttemptElapsedMillis = mFakeElapsedRealtimeClock.getElapsedRealtimeMillis(); + + NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult1); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); + + // The next wake-up should be rescheduled using the normalPollingIntervalMillis. + // Because the time signal age > normalPollingIntervalMillis, the last refresh attempt + // time will be used. + long expectedDelayMillis = normalPollingIntervalMillis; + long expectedNextRefreshElapsedMillis = + lastRefreshAttemptElapsedMillis + expectedDelayMillis; + verify(mockCallback).scheduleNextRefresh(expectedNextRefreshElapsedMillis); + + reset(mMockNtpTrustedTime); + } + + // Now fail: This should result in the next refresh using a short polling interval. + { + mFakeElapsedRealtimeClock.incrementMillis(normalPollingIntervalMillis); + when(mMockNtpTrustedTime.getCachedTimeResult()).thenReturn(timeResult1); + when(mMockNtpTrustedTime.forceRefresh(mDummyNetwork)).thenReturn(false); + + RefreshCallbacks mockCallback = mock(RefreshCallbacks.class); + // Trigger the engine's logic. + engine.refreshAndRescheduleIfRequired(mDummyNetwork, "Test", mockCallback); + + verify(mMockNtpTrustedTime, times(1)).forceRefresh(mDummyNetwork); + lastRefreshAttemptElapsedMillis = mFakeElapsedRealtimeClock.getElapsedRealtimeMillis(); + // Suggestions should not be made if the cached time value is too old. verify(mockCallback, never()).submitSuggestion(any()); + // The next wake-up should be rescheduled using the last refresh attempt time (because + // the latest time result is too old) and the short polling interval. + long expectedDelayMillis = shortPollingIntervalMillis; + long expectedNextRefreshElapsedMillis = + lastRefreshAttemptElapsedMillis + expectedDelayMillis; + verify(mockCallback).scheduleNextRefresh(expectedNextRefreshElapsedMillis); + reset(mMockNtpTrustedTime); } + + // Simulate some other thread successfully refreshing the value held by NtpTrustedTime and + // confirm it is handled correctly. + { + mFakeElapsedRealtimeClock.incrementMillis(shortPollingIntervalMillis / 2); + NtpTrustedTime.TimeResult timeResult2 = createNtpTimeResult( + mFakeElapsedRealtimeClock.getElapsedRealtimeMillis()); + when(mMockNtpTrustedTime.getCachedTimeResult()).thenReturn(timeResult2); + + mFakeElapsedRealtimeClock.incrementMillis(shortPollingIntervalMillis / 2); + + RefreshCallbacks mockCallback = mock(RefreshCallbacks.class); + // Trigger the engine's logic. + engine.refreshAndRescheduleIfRequired(mDummyNetwork, "Test", mockCallback); + + verify(mMockNtpTrustedTime, never()).forceRefresh(any()); + + NetworkTimeSuggestion expectedSuggestion = createExpectedSuggestion(timeResult2); + verify(mockCallback, times(1)).submitSuggestion(expectedSuggestion); + + // The next wake-up should be rescheduled using the normal polling interval and the + // latest time result. + long expectedDelayMillis = normalPollingIntervalMillis; + long expectedNextRefreshElapsedMillis = + timeResult2.getElapsedRealtimeMillis() + expectedDelayMillis; + verify(mockCallback).scheduleNextRefresh(expectedNextRefreshElapsedMillis); + } } private static NetworkTimeSuggestion createExpectedSuggestion( |