Merge "Cancel Syncs that aren't making progress." into mnc-dev

core/java/android/content/AbstractThreadedSyncAdapter.java

@@ -28,13 +28,26 @@ import java.util.concurrent.atomic.AtomicInteger;
 
 /**
  * An abstract implementation of a SyncAdapter that spawns a thread to invoke a sync operation.
- * If a sync operation is already in progress when a startSync() request is received then an error
+ * If a sync operation is already in progress when a sync request is received, an error will be
- * will be returned to the new request and the existing request will be allowed to continue.
+ * returned to the new request and the existing request will be allowed to continue.
- * When a startSync() is received and there is no sync operation in progress then a thread
+ * However if there is no sync in progress then a thread will be spawned and {@link #onPerformSync}
- * will be started to run the operation and {@link #onPerformSync} will be invoked on that thread.
+ * will be invoked on that thread.
- * If a cancelSync() is received that matches an existing sync operation then the thread
+ * <p>
- * that is running that sync operation will be interrupted, which will indicate to the thread
+ * Syncs can be cancelled at any time by the framework. For example a sync that was not
- * that the sync has been canceled.
+ * user-initiated and lasts longer than 30 minutes will be considered timed-out and cancelled.
+ * Similarly the framework will attempt to determine whether or not an adapter is making progress
+ * by monitoring its network activity over the course of a minute. If the network traffic over this
+ * window is close enough to zero the sync will be cancelled. You can also request the sync be
+ * cancelled via {@link ContentResolver#cancelSync(Account, String)} or
+ * {@link ContentResolver#cancelSync(SyncRequest)}.
+ * <p>
+ * A sync is cancelled by issuing a {@link Thread#interrupt()} on the syncing thread. <strong>Either
+ * your code in {@link #onPerformSync(Account, Bundle, String, ContentProviderClient, SyncResult)}
+ * must check {@link Thread#interrupted()}, or you you must override one of
+ * {@link #onSyncCanceled(Thread)}/{@link #onSyncCanceled()}</strong> (depending on whether or not
+ * your adapter supports syncing of multiple accounts in parallel). If your adapter does not
+ * respect the cancel issued by the framework you run the risk of your app's entire process being
+ * killed.
  * <p>
  * In order to be a sync adapter one must extend this class, provide implementations for the
  * abstract methods and write a service that returns the result of {@link #getSyncAdapterBinder()}

services/core/java/com/android/server/content/SyncManager.java

@@ -55,6 +55,7 @@ import android.content.pm.UserInfo;
 import android.database.ContentObserver;
 import android.net.ConnectivityManager;
 import android.net.NetworkInfo;
+import android.net.TrafficStats;
 import android.os.BatteryStats;
 import android.os.Bundle;
 import android.os.Handler;
@@ -100,7 +101,6 @@ import java.util.Comparator;
 import java.util.HashMap;
 import java.util.HashSet;
 import java.util.Iterator;
-import java.util.LinkedList;
 import java.util.List;
 import java.util.Map;
 import java.util.Random;
@@ -161,6 +161,19 @@ public class SyncManager {
      */
     private static final long ACTIVE_SYNC_TIMEOUT_MILLIS = 30L * 60 * 1000;  // 30 mins
 
+    /**
+     * How often to periodically poll network traffic for an adapter performing a sync to determine
+     * whether progress is being made.
+     */
+    private static final long SYNC_MONITOR_WINDOW_LENGTH_MILLIS = 60 * 1000; // 60 seconds
+
+    /**
+     * How many bytes must be transferred (Tx + Rx) over the period of time defined by
+     * {@link #SYNC_MONITOR_WINDOW_LENGTH_MILLIS} for the sync to be considered to be making
+     * progress.
+     */
+    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.
@@ -957,20 +970,42 @@ public class SyncManager {
     }
 
     /**
-     * Remove any time-outs previously posted for the provided active sync.
+     * Post a delayed message that will monitor the given sync context by periodically checking how
+     * much network has been used by the uid.
      */
-    private void removeSyncExpiryMessage(ActiveSyncContext activeSyncContext) {
+    private void postMonitorSyncProgressMessage(ActiveSyncContext activeSyncContext) {
         if (Log.isLoggable(TAG, Log.VERBOSE)) {
-            Log.v(TAG, "removing all MESSAGE_SYNC_EXPIRED for " + activeSyncContext.toString());
+            Log.v(TAG, "posting MESSAGE_SYNC_MONITOR in " +
+                    (SYNC_MONITOR_WINDOW_LENGTH_MILLIS/1000) + "s");
         }
-        mSyncHandler.removeMessages(SyncHandler.MESSAGE_SYNC_EXPIRED, activeSyncContext);
+
+        activeSyncContext.mBytesTransferredAtLastPoll =
+                getTotalBytesTransferredByUid(activeSyncContext.mSyncAdapterUid);
+        activeSyncContext.mLastPolledTimeElapsed = SystemClock.elapsedRealtime();
+        Message monitorMessage =
+                mSyncHandler.obtainMessage(
+                        SyncHandler.MESSAGE_MONITOR_SYNC,
+                        activeSyncContext);
+        mSyncHandler.sendMessageDelayed(monitorMessage, SYNC_MONITOR_WINDOW_LENGTH_MILLIS);
     }
 
+    /**
+     * Monitor sync progress by calculating how many bytes it is managing to send to and fro.
+     */
+    private long getTotalBytesTransferredByUid(int uid) {
+        return (TrafficStats.getUidRxBytes(uid) + TrafficStats.getUidTxBytes(uid));
+    }
+
+    /**
+     * Convenience class for passing parameters for a finished or cancelled sync to the handler
+     * to be processed.
+     */
     class SyncHandlerMessagePayload {
         public final ActiveSyncContext activeSyncContext;
         public final SyncResult syncResult;
 
-        SyncHandlerMessagePayload(ActiveSyncContext syncContext, SyncResult syncResult) {
+        SyncHandlerMessagePayload(ActiveSyncContext syncContext,
+                                  SyncResult syncResult) {
             this.activeSyncContext = syncContext;
             this.syncResult = syncResult;
         }
@@ -1277,6 +1312,14 @@ public class SyncManager {
         boolean mIsLinkedToDeath = false;
         String mEventName;
 
+        /** Total bytes transferred, counted at {@link #mLastPolledTimeElapsed} */
+        long mBytesTransferredAtLastPoll;
+        /**
+         * Last point in {@link SystemClock#elapsedRealtime()} at which we checked the # of bytes
+         * transferred to/fro by this adapter.
+         */
+        long mLastPolledTimeElapsed;
+
         /**
          * Create an ActiveSyncContext for an impending sync and grab the wakelock for that
          * sync adapter. Since this grabs the wakelock you need to be sure to call
@@ -2048,8 +2091,16 @@ public class SyncManager {
         private static final int MESSAGE_SERVICE_CONNECTED = 4;
         private static final int MESSAGE_SERVICE_DISCONNECTED = 5;
         private static final int MESSAGE_CANCEL = 6;
-        /** Posted delayed in order to expire syncs that are long-running. */
+        /**
+         * Posted delayed in order to expire syncs that are long-running.
+         * obj: {@link com.android.server.content.SyncManager.ActiveSyncContext}
+         */
         private static final int MESSAGE_SYNC_EXPIRED = 7;
+        /**
+         * Posted periodically to monitor network process for long-running syncs.
+         * obj: {@link com.android.server.content.SyncManager.ActiveSyncContext}
+         */
+        private static final int MESSAGE_MONITOR_SYNC = 8;
 
         public final SyncNotificationInfo mSyncNotificationInfo = new SyncNotificationInfo();
         private Long mAlarmScheduleTime = null;
@@ -2167,28 +2218,16 @@ public class SyncManager {
                 // to also take into account the periodic syncs.
                 earliestFuturePollTime = scheduleReadyPeriodicSyncs();
                 switch (msg.what) {
-                    case SyncHandler.MESSAGE_SYNC_EXPIRED:
+                    case SyncHandler.MESSAGE_CANCEL:
-                        ActiveSyncContext expiredContext = (ActiveSyncContext) msg.obj;
+                        SyncStorageEngine.EndPoint endpoint = (SyncStorageEngine.EndPoint) msg.obj;
-                        if (Log.isLoggable(TAG, Log.DEBUG)) {
-                            Log.d(TAG, "handleSyncHandlerMessage: MESSAGE_SYNC_EXPIRED: expiring "
-                                    + expiredContext);
-                        }
-                        cancelActiveSync(expiredContext.mSyncOperation.target,
-                                expiredContext.mSyncOperation.extras);
-                        nextPendingSyncTime = maybeStartNextSyncH();
-                        break;
-
-                    case SyncHandler.MESSAGE_CANCEL: {
-                        SyncStorageEngine.EndPoint payload = (SyncStorageEngine.EndPoint) msg.obj;
                         Bundle extras = msg.peekData();
                         if (Log.isLoggable(TAG, Log.DEBUG)) {
-                            Log.d(TAG, "handleSyncHandlerMessage: MESSAGE_SERVICE_CANCEL: "
+                            Log.d(TAG, "handleSyncHandlerMessage: MESSAGE_CANCEL: "
-                                    + payload + " bundle: " + extras);
+                                    + endpoint + " bundle: " + extras);
                         }
-                        cancelActiveSyncLocked(payload, extras);
+                        cancelActiveSyncH(endpoint, extras);
                         nextPendingSyncTime = maybeStartNextSyncH();
                         break;
-                    }
 
                     case SyncHandler.MESSAGE_SYNC_FINISHED:
                         if (Log.isLoggable(TAG, Log.VERBOSE)) {
@@ -2254,7 +2293,6 @@ public class SyncManager {
                             // since a sync just finished check if it is time to start a new sync
                             nextPendingSyncTime = maybeStartNextSyncH();
                         }
-
                         break;
                     }
 
@@ -2278,6 +2316,36 @@ public class SyncManager {
                         }
                         nextPendingSyncTime = maybeStartNextSyncH();
                         break;
+                    case SyncHandler.MESSAGE_SYNC_EXPIRED:
+                        ActiveSyncContext expiredContext = (ActiveSyncContext) msg.obj;
+                        if (Log.isLoggable(TAG, Log.DEBUG)) {
+                            Log.d(TAG, "handleSyncHandlerMessage: MESSAGE_SYNC_EXPIRED:" +
+                                    " cancelling " + expiredContext);
+                        }
+                        runSyncFinishedOrCanceledH(
+                                null /* cancel => no result */,
+                                expiredContext);
+                        nextPendingSyncTime = maybeStartNextSyncH();
+                        break;
+                    case SyncHandler.MESSAGE_MONITOR_SYNC:
+                        ActiveSyncContext monitoredSyncContext = (ActiveSyncContext) msg.obj;
+                        if (Log.isLoggable(TAG, Log.DEBUG)) {
+                            Log.d(TAG, "handleSyncHandlerMessage: MESSAGE_MONITOR_SYNC: " +
+                                    monitoredSyncContext.mSyncOperation.target);
+                        }
+
+                        if (isSyncNotUsingNetworkH(monitoredSyncContext)) {
+                            Log.w(TAG, String.format(
+                                    "Detected sync making no progress for %s. cancelling.",
+                                    monitoredSyncContext));
+                            runSyncFinishedOrCanceledH(
+                                    null /* cancel => no result */, monitoredSyncContext);
+                        } else {
+                            // Repost message to check again.
+                            postMonitorSyncProgressMessage(monitoredSyncContext);
+                        }
+                    break;
+
                 }
             } finally {
                 manageSyncNotificationLocked();
@@ -2699,6 +2767,30 @@ public class SyncManager {
             return nextReadyToRunTime;
         }
 
+        private boolean isSyncNotUsingNetworkH(ActiveSyncContext activeSyncContext) {
+            final long bytesTransferredCurrent =
+                    getTotalBytesTransferredByUid(activeSyncContext.mSyncAdapterUid);
+            final long deltaBytesTransferred =
+                    bytesTransferredCurrent - activeSyncContext.mBytesTransferredAtLastPoll;
+
+            if (Log.isLoggable(TAG, Log.DEBUG)) {
+                // Bytes transferred
+                long remainder = deltaBytesTransferred;
+                long mb = remainder / (1024 * 1024);
+                remainder %= 1024 * 1024;
+                long kb = remainder / 1024;
+                remainder %= 1024;
+                long b = remainder;
+                Log.d(TAG, String.format(
+                                "Time since last update: %ds. Delta transferred: %dMBs,%dKBs,%dBs",
+                                (SystemClock.elapsedRealtime()
+                                        - activeSyncContext.mLastPolledTimeElapsed)/1000,
+                                mb, kb, b)
+                );
+            }
+            return (deltaBytesTransferred <= SYNC_MONITOR_PROGRESS_THRESHOLD_BYTES);
+        }
+
         /**
          * Determine if a sync is no longer valid and should be dropped from the sync queue and its
          * pending op deleted.
@@ -2849,18 +2941,22 @@ public class SyncManager {
             }
             ActiveSyncContext activeSyncContext =
                     new ActiveSyncContext(op, insertStartSyncEvent(op), targetUid);
-            activeSyncContext.mSyncInfo = mSyncStorageEngine.addActiveSync(activeSyncContext);
-            mActiveSyncContexts.add(activeSyncContext);
-            if (!activeSyncContext.mSyncOperation.isInitialization() &&
-                    !activeSyncContext.mSyncOperation.isExpedited() &&
-                    !activeSyncContext.mSyncOperation.isManual() &&
-                    !activeSyncContext.mSyncOperation.isIgnoreSettings()) {
-                // Post message to expire this sync if it runs for too long.
-                postSyncExpiryMessage(activeSyncContext);
-            }
             if (Log.isLoggable(TAG, Log.VERBOSE)) {
                 Log.v(TAG, "dispatchSyncOperation: starting " + activeSyncContext);
             }
+
+            activeSyncContext.mSyncInfo = mSyncStorageEngine.addActiveSync(activeSyncContext);
+            mActiveSyncContexts.add(activeSyncContext);
+            // Post message to cancel this sync if it runs for too long.
+            if (!activeSyncContext.mSyncOperation.isExpedited() &&
+                    !activeSyncContext.mSyncOperation.isManual() &&
+                    !activeSyncContext.mSyncOperation.isIgnoreSettings()) {
+                postSyncExpiryMessage(activeSyncContext);
+            }
+
+            // Post message to begin monitoring this sync's progress.
+            postMonitorSyncProgressMessage(activeSyncContext);
+
             if (!activeSyncContext.bindToSyncAdapter(targetComponent, info.userId)) {
                 Log.e(TAG, "Bind attempt failed - target: " + targetComponent);
                 closeActiveSyncContext(activeSyncContext);
@@ -2902,9 +2998,10 @@ public class SyncManager {
 
         /**
          * Cancel the sync for the provided target that matches the given bundle.
-         * @param info can have null fields to indicate all the active syncs for that field.
+         * @param info Can have null fields to indicate all the active syncs for that field.
+         * @param extras Can be null to indicate <strong>all</strong> syncs for the given endpoint.
          */
-        private void cancelActiveSyncLocked(SyncStorageEngine.EndPoint info, Bundle extras) {
+        private void cancelActiveSyncH(SyncStorageEngine.EndPoint info, Bundle extras) {
             ArrayList<ActiveSyncContext> activeSyncs =
                     new ArrayList<ActiveSyncContext>(mActiveSyncContexts);
             for (ActiveSyncContext activeSyncContext : activeSyncs) {
@@ -2920,8 +3017,7 @@ public class SyncManager {
                                     false /* no config settings */)) {
                         continue;
                     }
-                    runSyncFinishedOrCanceledH(null /* no result since this is a cancel */,
+                    runSyncFinishedOrCanceledH(null /* cancel => no result */, activeSyncContext);
-                            activeSyncContext);
                 }
             }
         }
@@ -3034,7 +3130,13 @@ public class SyncManager {
             mActiveSyncContexts.remove(activeSyncContext);
             mSyncStorageEngine.removeActiveSync(activeSyncContext.mSyncInfo,
                     activeSyncContext.mSyncOperation.target.userId);
-            removeSyncExpiryMessage(activeSyncContext);
+
+            if (Log.isLoggable(TAG, Log.VERBOSE)) {
+                Log.v(TAG, "removing all MESSAGE_MONITOR_SYNC & MESSAGE_SYNC_EXPIRED for "
+                        + activeSyncContext.toString());
+            }
+            mSyncHandler.removeMessages(SyncHandler.MESSAGE_SYNC_EXPIRED, activeSyncContext);
+            mSyncHandler.removeMessages(SyncHandler.MESSAGE_MONITOR_SYNC, activeSyncContext);
         }
 
         /**