From 1675400a7cd0b56e5adc5606fb4fea77f8d24ea5 Mon Sep 17 00:00:00 2001 From: Shreyas Basarge Date: Mon, 8 Feb 2016 23:52:27 +0000 Subject: [PATCH] SyncManager sync blow up fix Duplicates for periodic syncs would be created just after boot and when a periodic sync was delayed. This CL fixes the behavior. Bug: 26954967 Change-Id: I2440961629d443a62f96360563d435af9137857b --- .../com/android/server/content/SyncManager.java | 163 ++++++++++++++------- .../com/android/server/content/SyncOperation.java | 93 ++++++------ .../android/server/content/SyncOperationTest.java | 10 +- 3 files changed, 160 insertions(+), 106 deletions(-) diff --git a/services/core/java/com/android/server/content/SyncManager.java b/services/core/java/com/android/server/content/SyncManager.java index daf839a59e1b..8dec5870427c 100644 --- a/services/core/java/com/android/server/content/SyncManager.java +++ b/services/core/java/com/android/server/content/SyncManager.java @@ -96,6 +96,7 @@ import java.io.PrintWriter; import java.util.ArrayList; import java.util.Random; import java.util.List; +import java.util.Set; import java.util.HashSet; import java.util.Collection; import java.util.Collections; @@ -178,18 +179,6 @@ public class SyncManager { private static final int SYNC_MONITOR_PROGRESS_THRESHOLD_BYTES = 10; // 10 bytes /** - * How long to delay each queued {@link SyncHandler} message that may have occurred before boot - * or befor the device became provisioned. - */ - private static final long PER_SYNC_BOOT_DELAY_MILLIS = 1000L; // 1 second - - /** - * The maximum amount of time we're willing to delay syncs out of boot, after device has been - * provisioned, etc. - */ - private static final long MAX_SYNC_BOOT_DELAY_MILLIS = 60000L; // 1 minute - - /** * If a previously scheduled sync becomes ready and we are low on storage, it gets * pushed back for this amount of time. */ @@ -242,12 +231,24 @@ public class SyncManager { private SparseArray mScheduledSyncs = new SparseArray(32); private final Random mRand; - private int getUnusedJobId() { + private boolean isJobIdInUseLockedH(int jobId) { + if (mScheduledSyncs.indexOfKey(jobId) >= 0) { + return true; + } + for (ActiveSyncContext asc: mActiveSyncContexts) { + if (asc.mSyncOperation.jobId == jobId) { + return true; + } + } + return false; + } + + private int getUnusedJobIdH() { synchronized (mScheduledSyncs) { - int newJobId = mRand.nextInt(Integer.MAX_VALUE); - while (mScheduledSyncs.indexOfKey(newJobId) >= 0) { + int newJobId; + do { newJobId = mRand.nextInt(Integer.MAX_VALUE); - } + } while (isJobIdInUseLockedH(newJobId)); return newJobId; } } @@ -425,6 +426,35 @@ public class SyncManager { } } + /** + * Cancel all unnecessary jobs. This function will be run once after every boot. + */ + private void cleanupJobs() { + // O(n^2) in number of jobs, so we run this on the background thread. + mSyncHandler.postAtFrontOfQueue(new Runnable() { + @Override + public void run() { + List ops = getAllPendingSyncsFromCache(); + Set cleanedKeys = new HashSet(); + for (SyncOperation opx: ops) { + if (cleanedKeys.contains(opx.key)) { + continue; + } + cleanedKeys.add(opx.key); + for (SyncOperation opy: ops) { + if (opx == opy) { + continue; + } + if (opx.key.equals(opy.key)) { + removeSyncOperationFromCache(opy.jobId); + mJobScheduler.cancel(opy.jobId); + } + } + } + } + }); + } + private synchronized void verifyJobScheduler() { if (mJobScheduler != null) { return; @@ -449,6 +479,7 @@ public class SyncManager { } } } + cleanupJobs(); } private JobScheduler getJobScheduler() { @@ -722,7 +753,6 @@ public class SyncManager { String requestedAuthority, Bundle extras, long beforeRuntimeMillis, long runtimeMillis, boolean onlyThoseWithUnkownSyncableState) { final boolean isLoggable = Log.isLoggable(TAG, Log.VERBOSE); - EndPoint ep = new EndPoint(requestedAccount,requestedAuthority, userId); if (extras == null) { extras = new Bundle(); } @@ -1197,7 +1227,18 @@ public class SyncManager { } // Check if duplicate syncs are pending. If found, keep one with least expected run time. - if (!syncOperation.isReasonPeriodic()) { + if (!syncOperation.isPeriodic) { + // Check currently running syncs + for (ActiveSyncContext asc: mActiveSyncContexts) { + if (asc.mSyncOperation.key.equals(syncOperation.key)) { + if (isLoggable) { + Log.v(TAG, "Duplicate sync is already running. Not scheduling " + + syncOperation); + } + return; + } + } + int duplicatesCount = 0; long now = SystemClock.elapsedRealtime(); syncOperation.expectedRuntime = now + minDelay; @@ -1240,14 +1281,16 @@ public class SyncManager { } } - syncOperation.jobId = getUnusedJobId(); + // Syncs that are re-scheduled shouldn't get a new job id. + if (syncOperation.jobId == SyncOperation.NO_JOB_ID) { + syncOperation.jobId = getUnusedJobIdH(); + } addSyncOperationToCache(syncOperation); if (isLoggable) { - Slog.v(TAG, "scheduling sync operation " + syncOperation.target.toString()); + Slog.v(TAG, "scheduling sync operation " + syncOperation.toString()); } - // This is done to give preference to syncs that are not pushed back. int priority = syncOperation.findPriority(); final int networkType = syncOperation.isNotAllowedOnMetered() ? @@ -1343,7 +1386,7 @@ public class SyncManager { Log.d(TAG, "retrying sync operation as a two-way sync because an upload-only sync " + "encountered an error: " + operation); } - scheduleSyncOperationH(operation, 0 /* immediately */); + scheduleSyncOperationH(operation); } else if (syncResult.tooManyRetries) { // If this sync aborted because the internal sync loop retried too many times then // don't reschedule. Otherwise we risk getting into a retry loop. @@ -1357,7 +1400,7 @@ public class SyncManager { Log.d(TAG, "retrying sync operation because even though it had an error " + "it achieved some success"); } - scheduleSyncOperationH(operation, 0 /* immediately */); + scheduleSyncOperationH(operation); } else if (syncResult.syncAlreadyInProgress) { if (isLoggable) { Log.d(TAG, "retrying sync operation that failed because there was already a " @@ -2207,7 +2250,8 @@ public class SyncManager { synchronized (this) { if (!mBootCompleted || !mProvisioned) { if (msg.what == MESSAGE_START_SYNC) { - deferSyncH((SyncOperation) msg.obj, 60*1000 /* 1 minute */); + SyncOperation op = (SyncOperation) msg.obj; + addSyncOperationToCache(op); } // Need to copy the message bc looper will recycle it. Message m = Message.obtain(msg); @@ -2272,21 +2316,24 @@ public class SyncManager { case MESSAGE_STOP_SYNC: op = (SyncOperation) msg.obj; - boolean reschedule = msg.arg1 != 0; - boolean applyBackoff = msg.arg2 != 0; if (isLoggable) { - Slog.v(TAG, "Stop sync received. Reschedule: " + reschedule - + "Backoff: " + applyBackoff); - } - if (applyBackoff) { - increaseBackoffSetting(op.target); - } - if (reschedule) { - scheduleSyncOperationH(op); + Slog.v(TAG, "Stop sync received."); } ActiveSyncContext asc = findActiveSyncContextH(op.jobId); if (asc != null) { runSyncFinishedOrCanceledH(null /* no result */, asc); + boolean reschedule = msg.arg1 != 0; + boolean applyBackoff = msg.arg2 != 0; + if (isLoggable) { + Slog.v(TAG, "Stopping sync. Reschedule: " + reschedule + + "Backoff: " + applyBackoff); + } + if (applyBackoff) { + increaseBackoffSetting(op.target); + } + if (reschedule) { + deferStoppedSyncH(op, 0); + } } break; @@ -2414,7 +2461,8 @@ public class SyncManager { /** * Defer the specified SyncOperation by rescheduling it on the JobScheduler with some - * delay. + * delay. This is equivalent to a failure. If this is a periodic sync, a delayed one-off + * sync will be scheduled. */ private void deferSyncH(SyncOperation op, long delay) { mSyncJobService.callJobFinished(op.jobId, false); @@ -2426,14 +2474,22 @@ public class SyncManager { } } + /* Same as deferSyncH, but assumes that job is no longer running on JobScheduler. */ + private void deferStoppedSyncH(SyncOperation op, long delay) { + if (op.isPeriodic) { + scheduleSyncOperationH(op.createOneTimeSyncOperation(), delay); + } else { + removeSyncOperationFromCache(op.jobId); + scheduleSyncOperationH(op, delay); + } + } + /** * Cancel an active sync and reschedule it on the JobScheduler with some delay. */ private void deferActiveSyncH(ActiveSyncContext asc) { SyncOperation op = asc.mSyncOperation; - - mSyncHandler.obtainMessage(MESSAGE_STOP_SYNC, 0 /* no reschedule */, - 0 /* no backoff */, op).sendToTarget(); + runSyncFinishedOrCanceledH(null, asc); deferSyncH(op, SYNC_DELAY_ON_CONFLICT); } @@ -2467,6 +2523,7 @@ public class SyncManager { // Check for adapter delays. if (isAdapterDelayed(op.target)) { deferSyncH(op, 0 /* No minimum delay */); + return; } } else { // Remove SyncOperation entry from mScheduledSyncs cache for non periodic jobs. @@ -2567,10 +2624,10 @@ public class SyncManager { Slog.v(TAG, "updating period " + syncOperation + " to " + pollFrequencyMillis + " and flex to " + flexMillis); } - removePeriodicSyncInternalH(syncOperation); - syncOperation.periodMillis = pollFrequencyMillis; - syncOperation.flexMillis = flexMillis; - scheduleSyncOperationH(syncOperation); + SyncOperation newOp = new SyncOperation(syncOperation, pollFrequencyMillis, + flexMillis); + newOp.jobId = syncOperation.jobId; + scheduleSyncOperationH(newOp); } } @@ -2614,9 +2671,8 @@ public class SyncManager { SyncOperation op = new SyncOperation(target, syncAdapterInfo.uid, syncAdapterInfo.componentName.getPackageName(), SyncOperation.REASON_PERIODIC, SyncStorageEngine.SOURCE_PERIODIC, extras, - syncAdapterInfo.type.allowParallelSyncs(), true, SyncOperation.NO_JOB_ID); - op.periodMillis = pollFrequencyMillis; - op.flexMillis = flexMillis; + syncAdapterInfo.type.allowParallelSyncs(), true, SyncOperation.NO_JOB_ID, + pollFrequencyMillis, flexMillis); scheduleSyncOperationH(op); mSyncStorageEngine.reportChange(ContentResolver.SYNC_OBSERVER_TYPE_SETTINGS); } @@ -2816,10 +2872,19 @@ public class SyncManager { * Should be called when a one-off instance of a periodic sync completes successfully. */ private void reschedulePeriodicSyncH(SyncOperation syncOperation) { - removeSyncOperationFromCache(syncOperation.sourcePeriodicId); - getJobScheduler().cancel(syncOperation.sourcePeriodicId); - SyncOperation periodic = syncOperation.createPeriodicSyncOperation(); - scheduleSyncOperationH(periodic); + // Ensure that the periodic sync wasn't removed. + SyncOperation periodicSync = null; + List ops = getAllPendingSyncsFromCache(); + for (SyncOperation op: ops) { + if (op.isPeriodic && syncOperation.matchesPeriodicOperation(op)) { + periodicSync = op; + break; + } + } + if (periodicSync == null) { + return; + } + scheduleSyncOperationH(periodicSync); } private void runSyncFinishedOrCanceledH(SyncResult syncResult, diff --git a/services/core/java/com/android/server/content/SyncOperation.java b/services/core/java/com/android/server/content/SyncOperation.java index 4fb31c0cda9f..957b0871715c 100644 --- a/services/core/java/com/android/server/content/SyncOperation.java +++ b/services/core/java/com/android/server/content/SyncOperation.java @@ -79,9 +79,9 @@ public class SyncOperation { public final String key; /** Poll frequency of periodic sync in milliseconds */ - public long periodMillis; + public final long periodMillis; /** Flex time of periodic sync in milliseconds */ - public long flexMillis; + public final long flexMillis; /** Descriptive string key for this operation */ public String wakeLockName; /** @@ -90,6 +90,9 @@ public class SyncOperation { */ public long expectedRuntime; + /** Stores the number of times this sync operation failed and had to be retried. */ + int retries; + /** jobId of the JobScheduler job corresponding to this sync */ public int jobId; @@ -103,23 +106,32 @@ public class SyncOperation { private SyncOperation(SyncStorageEngine.EndPoint info, int owningUid, String owningPackage, int reason, int source, Bundle extras, boolean allowParallelSyncs) { this(info, owningUid, owningPackage, reason, source, extras, allowParallelSyncs, false, - NO_JOB_ID); + NO_JOB_ID, 0, 0); + } + + public SyncOperation(SyncOperation op, long periodMillis, long flexMillis) { + this(op.target, op.owningUid, op.owningPackage, op.reason, op.syncSource, + new Bundle(op.extras), op.allowParallelSyncs, op.isPeriodic, op.sourcePeriodicId, + periodMillis, flexMillis); } public SyncOperation(SyncStorageEngine.EndPoint info, int owningUid, String owningPackage, int reason, int source, Bundle extras, boolean allowParallelSyncs, - boolean isPeriodic, int sourcePeriodicId) { + boolean isPeriodic, int sourcePeriodicId, long periodMillis, + long flexMillis) { this.target = info; this.owningUid = owningUid; this.owningPackage = owningPackage; this.reason = reason; this.syncSource = source; this.extras = new Bundle(extras); - cleanBundle(this.extras); this.allowParallelSyncs = allowParallelSyncs; this.isPeriodic = isPeriodic; this.sourcePeriodicId = sourcePeriodicId; - this.key = toKey(target, extras); + this.periodMillis = periodMillis; + this.flexMillis = flexMillis; + this.jobId = NO_JOB_ID; + this.key = toKey(); } /* Get a one off sync operation instance from a periodic sync. */ @@ -128,18 +140,8 @@ public class SyncOperation { return null; } SyncOperation op = new SyncOperation(target, owningUid, owningPackage, reason, syncSource, - new Bundle(extras), allowParallelSyncs, false, jobId /* sourcePeriodicId */); - // Copied to help us recreate the periodic sync from this one off sync. - op.periodMillis = periodMillis; - op.flexMillis = flexMillis; - return op; - } - - public SyncOperation createPeriodicSyncOperation() { - SyncOperation op = new SyncOperation(target, owningUid, owningPackage, reason, syncSource, - new Bundle(extras), allowParallelSyncs, true, NO_JOB_ID); - op.periodMillis = periodMillis; - op.flexMillis = flexMillis; + new Bundle(extras), allowParallelSyncs, false, jobId /* sourcePeriodicId */, + periodMillis, flexMillis); return op; } @@ -224,6 +226,7 @@ public class SyncOperation { jobInfoExtras.putLong("periodMillis", periodMillis); jobInfoExtras.putLong("flexMillis", flexMillis); jobInfoExtras.putLong("expectedRuntime", expectedRuntime); + jobInfoExtras.putInt("retries", retries); return jobInfoExtras; } @@ -240,6 +243,7 @@ public class SyncOperation { int initiatedBy; Bundle extras; boolean allowParallelSyncs, isPeriodic; + long periodMillis, flexMillis; if (!jobExtras.getBoolean("SyncManagerJob", false)) { return null; @@ -256,6 +260,8 @@ public class SyncOperation { allowParallelSyncs = jobExtras.getBoolean("allowParallelSyncs", false); isPeriodic = jobExtras.getBoolean("isPeriodic", false); initiatedBy = jobExtras.getInt("sourcePeriodicId", NO_JOB_ID); + periodMillis = jobExtras.getLong("periodMillis"); + flexMillis = jobExtras.getLong("flexMillis"); extras = new Bundle(); PersistableBundle syncExtras = jobExtras.getPersistableBundle("syncExtras"); @@ -277,38 +283,14 @@ public class SyncOperation { SyncStorageEngine.EndPoint target = new SyncStorageEngine.EndPoint(account, provider, userId); SyncOperation op = new SyncOperation(target, owningUid, owningPackage, reason, source, - extras, allowParallelSyncs, isPeriodic, initiatedBy); + extras, allowParallelSyncs, isPeriodic, initiatedBy, periodMillis, flexMillis); op.jobId = jobExtras.getInt("jobId"); - op.periodMillis = jobExtras.getLong("periodMillis"); - op.flexMillis = jobExtras.getLong("flexMillis"); op.expectedRuntime = jobExtras.getLong("expectedRuntime"); + op.retries = jobExtras.getInt("retries"); return op; } /** - * Make sure the bundle attached to this SyncOperation doesn't have unnecessary - * flags set. - * @param bundle to clean. - */ - private void cleanBundle(Bundle bundle) { - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_UPLOAD); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_MANUAL); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_IGNORE_SETTINGS); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_IGNORE_BACKOFF); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_DO_NOT_RETRY); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_DISCARD_LOCAL_DELETIONS); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_EXPEDITED); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_OVERRIDE_TOO_MANY_DELETIONS); - removeFalseExtra(bundle, ContentResolver.SYNC_EXTRAS_DISALLOW_METERED); - } - - private void removeFalseExtra(Bundle bundle, String extraName) { - if (!bundle.getBoolean(extraName, false)) { - bundle.remove(extraName); - } - } - - /** * Determine whether if this sync operation is running, the provided operation would conflict * with it. * Parallel syncs allow multiple accounts to be synced at the same time. @@ -326,6 +308,12 @@ public class SyncOperation { return reason == REASON_PERIODIC; } + boolean matchesPeriodicOperation(SyncOperation other) { + return target.matchesSpec(other.target) + && SyncManager.syncExtrasEquals(extras, other.extras, true) + && periodMillis == other.periodMillis && flexMillis == other.flexMillis; + } + boolean isDerivedFromFailedPeriodicSync() { return sourcePeriodicId != NO_JOB_ID; } @@ -339,15 +327,18 @@ public class SyncOperation { return 0; } - static String toKey(SyncStorageEngine.EndPoint info, Bundle extras) { + private String toKey() { StringBuilder sb = new StringBuilder(); - sb.append("provider: ").append(info.provider); - sb.append(" account {name=" + info.account.name + sb.append("provider: ").append(target.provider); + sb.append(" account {name=" + target.account.name + ", user=" - + info.userId + + target.userId + ", type=" - + info.account.type + + target.account.type + "}"); + sb.append(" isPeriodic: ").append(isPeriodic); + sb.append(" period: ").append(periodMillis); + sb.append(" flex: ").append(flexMillis); sb.append(" extras: "); extrasToStringBuilder(extras, sb); return sb.toString(); @@ -360,7 +351,9 @@ public class SyncOperation { String dump(PackageManager pm, boolean useOneLine) { StringBuilder sb = new StringBuilder(); - sb.append(target.account.name) + sb.append("JobId: ").append(jobId) + .append(", ") + .append(target.account.name) .append(" u") .append(target.userId).append(" (") .append(target.account.type) diff --git a/services/tests/servicestests/src/com/android/server/content/SyncOperationTest.java b/services/tests/servicestests/src/com/android/server/content/SyncOperationTest.java index 313dc8bac749..e45b92a1b486 100644 --- a/services/tests/servicestests/src/com/android/server/content/SyncOperationTest.java +++ b/services/tests/servicestests/src/com/android/server/content/SyncOperationTest.java @@ -145,14 +145,10 @@ public class SyncOperationTest extends AndroidTestCase { "provider", 0); Bundle extras = new Bundle(); SyncOperation periodic = new SyncOperation(ep, 0, "package", 0, 0, extras, false, true, - SyncOperation.NO_JOB_ID); - periodic.periodMillis = 60000; - periodic.flexMillis = 10000; + SyncOperation.NO_JOB_ID, 60000, 10000); SyncOperation oneoff = periodic.createOneTimeSyncOperation(); assertFalse("Conversion to oneoff sync failed.", oneoff.isPeriodic); - SyncOperation recreated = oneoff.createPeriodicSyncOperation(); - assertTrue("Conversion to periodic sync failed.", oneoff.isPeriodic); - assertEquals("Period not restored", periodic.periodMillis, recreated.periodMillis); - assertEquals("Flex not restored", periodic.flexMillis, recreated.flexMillis); + assertEquals("Period not restored", periodic.periodMillis, oneoff.periodMillis); + assertEquals("Flex not restored", periodic.flexMillis, oneoff.flexMillis); } } -- 2.11.0