Poll jobs' status to update notifications.

Bug: 27249491
Change-Id: I8912c781582af1789c8f76dea06879a3dde75d34

4 files changed, 162 insertions, 57 deletions

diff --git a/packages/DocumentsUI/src/com/android/documentsui/services/CopyJob.java b/packages/DocumentsUI/src/com/android/documentsui/services/CopyJob.java
index f10af4378c21..d6f2e5beeb09 100644
--- a/packages/DocumentsUI/src/com/android/documentsui/services/CopyJob.java
+++ b/packages/DocumentsUI/src/com/android/documentsui/services/CopyJob.java
@@ -21,6 +21,7 @@ import static android.provider.DocumentsContract.buildChildDocumentsUri;
 import static android.provider.DocumentsContract.buildDocumentUri;
 import static android.provider.DocumentsContract.getDocumentId;
 import static android.provider.DocumentsContract.isChildDocument;
+
 import static com.android.documentsui.OperationDialogFragment.DIALOG_TYPE_CONVERTED;
 import static com.android.documentsui.Shared.DEBUG;
 import static com.android.documentsui.model.DocumentInfo.getCursorLong;
@@ -45,8 +46,6 @@ import android.os.ParcelFileDescriptor;
 import android.os.RemoteException;
 import android.provider.DocumentsContract;
 import android.provider.DocumentsContract.Document;
-import android.system.ErrnoException;
-import android.system.Os;
 import android.text.format.DateUtils;
 import android.util.Log;
 import android.webkit.MimeTypeMap;
@@ -62,7 +61,6 @@ import libcore.io.IoUtils;
 import java.io.FileNotFoundException;
 import java.io.IOException;
 import java.io.InputStream;
-import java.io.OutputStream;
 import java.text.NumberFormat;
 import java.util.ArrayList;
 import java.util.List;
@@ -70,7 +68,6 @@ import java.util.List;
 class CopyJob extends Job {
 
     private static final String TAG = "CopyJob";
-    private static final int PROGRESS_INTERVAL_MILLIS = 500;
 
     final List<DocumentInfo> mSrcs;
     final ArrayList<DocumentInfo> convertedFiles = new ArrayList<>();
@@ -78,8 +75,7 @@ class CopyJob extends Job {
     private long mStartTime = -1;
 
     private long mBatchSize;
-    private long mBytesCopied;
-    private long mLastNotificationTime;
+    private volatile long mBytesCopied;
     // Speed estimation
     private long mBytesCopiedSample;
     private long mSampleTime;
@@ -127,16 +123,13 @@ class CopyJob extends Job {
         return getSetupNotification(service.getString(R.string.copy_preparing));
     }
 
-    public boolean shouldUpdateProgress() {
-        // Wait a while between updates :)
-        return elapsedRealtime() - mLastNotificationTime > PROGRESS_INTERVAL_MILLIS;
-    }
-
     Notification getProgressNotification(@StringRes int msgId) {
+        updateRemainingTimeEstimate();
+
         if (mBatchSize >= 0) {
             double completed = (double) this.mBytesCopied / mBatchSize;
             mProgressBuilder.setProgress(100, (int) (completed * 100), false);
-            mProgressBuilder.setContentInfo(
+            mProgressBuilder.setSubText(
                     NumberFormat.getPercentInstance().format(completed));
         } else {
             // If the total file size failed to compute on some files, then show
@@ -153,12 +146,10 @@ class CopyJob extends Job {
             mProgressBuilder.setContentText(null);
         }
 
-        // Remember when we last returned progress so we can provide an answer
-        // in shouldUpdateProgress.
-        mLastNotificationTime = elapsedRealtime();
         return mProgressBuilder.build();
     }
 
+    @Override
     public Notification getProgressNotification() {
         return getProgressNotification(R.string.copy_remaining);
     }
@@ -170,11 +161,14 @@ class CopyJob extends Job {
     /**
      * Generates an estimate of the remaining time in the copy.
      */
-    void updateRemainingTimeEstimate() {
+    private void updateRemainingTimeEstimate() {
         long elapsedTime = elapsedRealtime() - mStartTime;
 
+        // mBytesCopied is modified in worker thread, but this method is called in monitor thread,
+        // so take a snapshot of mBytesCopied to make sure the updated estimate is consistent.
+        final long bytesCopied = mBytesCopied;
         final long sampleDuration = elapsedTime - mSampleTime;
-        final long sampleSpeed = ((mBytesCopied - mBytesCopiedSample) * 1000) / sampleDuration;
+        final long sampleSpeed = ((bytesCopied - mBytesCopiedSample) * 1000) / sampleDuration;
         if (mSpeed == 0) {
             mSpeed = sampleSpeed;
         } else {
@@ -182,13 +176,13 @@ class CopyJob extends Job {
         }
 
         if (mSampleTime > 0 && mSpeed > 0) {
-            mRemainingTime = ((mBatchSize - mBytesCopied) * 1000) / mSpeed;
+            mRemainingTime = ((mBatchSize - bytesCopied) * 1000) / mSpeed;
         } else {
             mRemainingTime = 0;
         }
 
         mSampleTime = elapsedTime;
-        mBytesCopiedSample = mBytesCopied;
+        mBytesCopiedSample = bytesCopied;
     }
 
     @Override
@@ -273,10 +267,6 @@ class CopyJob extends Job {
      */
     private void makeCopyProgress(long bytesCopied) {
         onBytesCopied(bytesCopied);
-        if (shouldUpdateProgress()) {
-            updateRemainingTimeEstimate();
-            listener.onProgress(this);
-        }
     }
 
     /**
@@ -308,6 +298,7 @@ class CopyJob extends Job {
                     Log.e(TAG, "Provider side copy failed for: " + src.derivedUri
                             + " due to an exception: " + e);
                 }
+
                 // If optimized copy fails, then fallback to byte-by-byte copy.
                 if (DEBUG) Log.d(TAG, "Fallback to byte-by-byte copy for: " + src.derivedUri);
             }
@@ -418,14 +409,16 @@ class CopyJob extends Job {
                     src = DocumentInfo.fromCursor(cursor, srcDir.authority);
                     processDocument(src, srcDir, destDir);
                 } catch (RuntimeException e) {
-                    Log.e(TAG, "Failed to recursively process a file %s due to an exception."
-                            .format(srcDir.derivedUri.toString()), e);
+                    Log.e(TAG, String.format(
+                            "Failed to recursively process a file %s due to an exception.",
+                            srcDir.derivedUri.toString()), e);
                     success = false;
                 }
             }
         } catch (RuntimeException e) {
-            Log.e(TAG, "Failed to copy a file %s to %s. "
-                    .format(srcDir.derivedUri.toString(), destDir.derivedUri.toString()), e);
+            Log.e(TAG, String.format(
+                    "Failed to copy a file %s to %s. ",
+                    srcDir.derivedUri.toString(), destDir.derivedUri.toString()), e);
             success = false;
         } finally {
             IoUtils.closeQuietly(cursor);
diff --git a/packages/DocumentsUI/src/com/android/documentsui/services/DeleteJob.java b/packages/DocumentsUI/src/com/android/documentsui/services/DeleteJob.java
index 8f451623cf72..e9bdd2cfa92d 100644
--- a/packages/DocumentsUI/src/com/android/documentsui/services/DeleteJob.java
+++ b/packages/DocumentsUI/src/com/android/documentsui/services/DeleteJob.java
@@ -37,6 +37,8 @@ final class DeleteJob extends Job {
     private List<DocumentInfo> mSrcs;
     final DocumentInfo mSrcParent;
 
+    private volatile int mDocsProcessed = 0;
+
     /**
      * Moves files to a destination identified by {@code destination}.
      * Performs most work by delegating to CopyJob, then deleting
@@ -69,6 +71,17 @@ final class DeleteJob extends Job {
     }
 
     @Override
+    public Notification getProgressNotification() {
+        mProgressBuilder.setProgress(mSrcs.size(), mDocsProcessed, false);
+        String format = service.getString(R.string.delete_progress);
+        mProgressBuilder.setSubText(String.format(format, mDocsProcessed, mSrcs.size()));
+
+        mProgressBuilder.setContentText(null);
+
+        return mProgressBuilder.build();
+    }
+
+    @Override
     Notification getFailureNotification() {
         return getFailureNotification(
                 R.plurals.delete_error_notification_title, R.drawable.ic_menu_delete);
@@ -85,10 +98,17 @@ final class DeleteJob extends Job {
             if (DEBUG) Log.d(TAG, "Deleting document @ " + doc.derivedUri);
             try {
                 deleteDocument(doc, mSrcParent);
+
+                if (isCanceled()) {
+                    // Canceled, dump the rest of the work. Deleted docs are not recoverable.
+                    return;
+                }
             } catch (ResourceException e) {
                 Log.e(TAG, "Failed to delete document @ " + doc.derivedUri);
                 onFileFailed(doc);
             }
+
+            ++mDocsProcessed;
         }
         Metrics.logFileOperation(service, operationType, mSrcs, null);
     }
diff --git a/packages/DocumentsUI/src/com/android/documentsui/services/FileOperationService.java b/packages/DocumentsUI/src/com/android/documentsui/services/FileOperationService.java
index 36a279b347c6..a3bff90d7b7d 100644
--- a/packages/DocumentsUI/src/com/android/documentsui/services/FileOperationService.java
+++ b/packages/DocumentsUI/src/com/android/documentsui/services/FileOperationService.java
@@ -22,6 +22,7 @@ import android.annotation.IntDef;
 import android.app.NotificationManager;
 import android.app.Service;
 import android.content.Intent;
+import android.os.Handler;
 import android.os.IBinder;
 import android.os.PowerManager;
 import android.support.annotation.Nullable;
@@ -35,6 +36,7 @@ import com.android.documentsui.services.Job.Factory;
 
 import java.lang.annotation.Retention;
 import java.lang.annotation.RetentionPolicy;
+import java.util.ArrayList;
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
@@ -85,10 +87,13 @@ public class FileOperationService extends Service implements Job.Listener {
     // a sub-optimal arrangement.
     @VisibleForTesting ExecutorService executor;
 
-    // Use a separate thread pool to prioritize deletions
+    // Use a separate thread pool to prioritize deletions.
     @VisibleForTesting ExecutorService deletionExecutor;
     @VisibleForTesting Factory jobFactory;
 
+    // Use a handler to schedule monitor tasks.
+    @VisibleForTesting Handler handler;
+
     private PowerManager mPowerManager;
     private PowerManager.WakeLock mWakeLock;  // the wake lock, if held.
     private NotificationManager mNotificationManager;
@@ -113,6 +118,11 @@ public class FileOperationService extends Service implements Job.Listener {
             jobFactory = Job.Factory.instance;
         }
 
+        if (handler == null) {
+            // Monitor tasks are small enough to schedule them on main thread.
+            handler = new Handler();
+        }
+
         if (DEBUG) Log.d(TAG, "Created.");
         mPowerManager = getSystemService(PowerManager.class);
         mNotificationManager = getSystemService(NotificationManager.class);
@@ -121,11 +131,20 @@ public class FileOperationService extends Service implements Job.Listener {
     @Override
     public void onDestroy() {
         if (DEBUG) Log.d(TAG, "Shutting down executor.");
-        List<Runnable> unfinished = executor.shutdownNow();
+
+        List<Runnable> unfinishedCopies = executor.shutdownNow();
+        List<Runnable> unfinishedDeletions = deletionExecutor.shutdownNow();
+        List<Runnable> unfinished =
+                new ArrayList<>(unfinishedCopies.size() + unfinishedDeletions.size());
+        unfinished.addAll(unfinishedCopies);
+        unfinished.addAll(unfinishedDeletions);
         if (!unfinished.isEmpty()) {
             Log.w(TAG, "Shutting down, but executor reports running jobs: " + unfinished);
         }
+
         executor = null;
+        deletionExecutor = null;
+        handler = null;
         if (DEBUG) Log.d(TAG, "Destroyed.");
     }
 
@@ -154,7 +173,6 @@ public class FileOperationService extends Service implements Job.Listener {
         // Track the service supplied id so we can stop the service once we're out of work to do.
         mLastServiceId = serviceId;
 
-        Job job = null;
         synchronized (mRunning) {
             if (mWakeLock == null) {
                 mWakeLock = mPowerManager.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, TAG);
@@ -164,7 +182,7 @@ public class FileOperationService extends Service implements Job.Listener {
             DocumentInfo srcParent = intent.getParcelableExtra(EXTRA_SRC_PARENT);
             DocumentStack stack = intent.getParcelableExtra(Shared.EXTRA_STACK);
 
-            job = createJob(operationType, jobId, srcs, srcParent, stack);
+            Job job = createJob(operationType, jobId, srcs, srcParent, stack);
 
             if (job == null) {
                 return;
@@ -301,40 +319,45 @@ public class FileOperationService extends Service implements Job.Listener {
     @Override
     public void onStart(Job job) {
         if (DEBUG) Log.d(TAG, "onStart: " + job.id);
-        mNotificationManager.notify(job.id, NOTIFICATION_ID_PROGRESS, job.getSetupNotification());
+
+        // Show start up notification
+        mNotificationManager.notify(
+                job.id, NOTIFICATION_ID_PROGRESS, job.getSetupNotification());
+
+        // Set up related monitor
+        JobMonitor monitor = new JobMonitor(job, mNotificationManager, handler);
+        monitor.start();
     }
 
     @Override
     public void onFinished(Job job) {
+        assert(job.isFinished());
         if (DEBUG) Log.d(TAG, "onFinished: " + job.id);
 
-        // Dismiss the ongoing copy notification when the copy is done.
-        mNotificationManager.cancel(job.id, NOTIFICATION_ID_PROGRESS);
+        // Use the same thread of monitors to tackle notifications to avoid race conditions.
+        // Otherwise we may fail to dismiss progress notification.
+        handler.post(() -> {
+            // Dismiss the ongoing copy notification when the copy is done.
+            mNotificationManager.cancel(job.id, NOTIFICATION_ID_PROGRESS);
 
-        if (job.hasFailures()) {
-            Log.e(TAG, "Job failed on files: " + job.failedFiles.size() + ".");
-            mNotificationManager.notify(
-                job.id, NOTIFICATION_ID_FAILURE, job.getFailureNotification());
-        }
+            if (job.hasFailures()) {
+                Log.e(TAG, "Job failed on files: " + job.failedFiles.size() + ".");
+                mNotificationManager.notify(
+                        job.id, NOTIFICATION_ID_FAILURE, job.getFailureNotification());
+            }
 
-        if (job.hasWarnings()) {
-            if (DEBUG) Log.d(TAG, "Job finished with warnings.");
-            mNotificationManager.notify(
-                    job.id, NOTIFICATION_ID_WARNING, job.getWarningNotification());
-        }
+            if (job.hasWarnings()) {
+                if (DEBUG) Log.d(TAG, "Job finished with warnings.");
+                mNotificationManager.notify(
+                        job.id, NOTIFICATION_ID_WARNING, job.getWarningNotification());
+            }
+        });
 
         synchronized (mRunning) {
             deleteJob(job);
         }
     }
 
-    @Override
-    public void onProgress(CopyJob job) {
-        if (DEBUG) Log.d(TAG, "onProgress: " + job.id);
-        mNotificationManager.notify(
-                job.id, NOTIFICATION_ID_PROGRESS, job.getProgressNotification());
-    }
-
     private static final class JobRecord {
         private final Job job;
         private final Future<?> future;
@@ -345,6 +368,47 @@ public class FileOperationService extends Service implements Job.Listener {
         }
     }
 
+    /**
+     * A class used to periodically polls state of a job.
+     *
+     * <p>It's possible that jobs hang because underlying document providers stop responding. We
+     * still need to update notifications if jobs hang, so instead of jobs pushing their states,
+     * we poll states of jobs.
+     */
+    private static final class JobMonitor implements Runnable {
+        private static final long INITIAL_PROGRESS_DELAY_MILLIS = 10L;
+        private static final long PROGRESS_INTERVAL_MILLIS = 500L;
+
+        private final Job mJob;
+        private final NotificationManager mNotificationManager;
+        private final Handler mHandler;
+
+        private JobMonitor(Job job, NotificationManager notificationManager, Handler handler) {
+            mJob = job;
+            mNotificationManager = notificationManager;
+            mHandler = handler;
+        }
+
+        private void start() {
+            // Delay the first update to avoid dividing by 0 when calculate speed
+            mHandler.postDelayed(this, INITIAL_PROGRESS_DELAY_MILLIS);
+        }
+
+        @Override
+        public void run() {
+            if (mJob.isFinished()) {
+                // Finish notification is already shown. Progress notification is removed.
+                // Just finish itself.
+                return;
+            }
+
+            mNotificationManager.notify(
+                    mJob.id, NOTIFICATION_ID_PROGRESS, mJob.getProgressNotification());
+
+            mHandler.postDelayed(this, PROGRESS_INTERVAL_MILLIS);
+        }
+    }
+
     @Override
     public IBinder onBind(Intent intent) {
         return null;  // Boilerplate. See super#onBind
diff --git a/packages/DocumentsUI/src/com/android/documentsui/services/Job.java b/packages/DocumentsUI/src/com/android/documentsui/services/Job.java
index b8f8fba72d62..fc3a73171add 100644
--- a/packages/DocumentsUI/src/com/android/documentsui/services/Job.java
+++ b/packages/DocumentsUI/src/com/android/documentsui/services/Job.java
@@ -25,6 +25,7 @@ import static com.android.documentsui.services.FileOperationService.EXTRA_SRC_LI
 import static com.android.documentsui.services.FileOperationService.OPERATION_UNKNOWN;
 
 import android.annotation.DrawableRes;
+import android.annotation.IntDef;
 import android.annotation.PluralsRes;
 import android.app.Notification;
 import android.app.Notification.Builder;
@@ -48,6 +49,8 @@ import com.android.documentsui.model.DocumentInfo;
 import com.android.documentsui.model.DocumentStack;
 import com.android.documentsui.services.FileOperationService.OpType;
 
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
 import java.util.ArrayList;
 import java.util.HashMap;
 import java.util.List;
@@ -60,6 +63,18 @@ import java.util.Map;
 abstract public class Job implements Runnable {
     private static final String TAG = "Job";
 
+    @Retention(RetentionPolicy.SOURCE)
+    @IntDef({STATE_CREATED, STATE_STARTED, STATE_COMPLETED, STATE_CANCELED})
+    @interface State {}
+    static final int STATE_CREATED = 0;
+    static final int STATE_STARTED = 1;
+    static final int STATE_COMPLETED = 2;
+    /**
+     * A job is in canceled state as long as {@link #cancel()} is called on it, even after it is
+     * completed.
+     */
+    static final int STATE_CANCELED = 3;
+
     static final String INTENT_TAG_WARNING = "warning";
     static final String INTENT_TAG_FAILURE = "failure";
     static final String INTENT_TAG_PROGRESS = "progress";
@@ -77,7 +92,7 @@ abstract public class Job implements Runnable {
     final Notification.Builder mProgressBuilder;
 
     private final Map<String, ContentProviderClient> mClients = new HashMap<>();
-    private volatile boolean mCanceled;
+    private volatile @State int mState = STATE_CREATED;
 
     /**
      * A simple progressable job, much like an AsyncTask, but with support
@@ -111,6 +126,12 @@ abstract public class Job implements Runnable {
 
     @Override
     public final void run() {
+        if (isCanceled()) {
+            // Canceled before running
+            return;
+        }
+
+        mState = STATE_STARTED;
         listener.onStart(this);
         try {
             start();
@@ -120,6 +141,7 @@ abstract public class Job implements Runnable {
             Log.e(TAG, "Operation failed due to an unhandled runtime exception.", e);
             Metrics.logFileOperationErrors(service, operationType, failedFiles);
         } finally {
+            mState = (mState == STATE_STARTED) ? STATE_COMPLETED : mState;
             listener.onFinished(this);
         }
     }
@@ -127,8 +149,7 @@ abstract public class Job implements Runnable {
     abstract void start();
 
     abstract Notification getSetupNotification();
-    // TODO: Progress notification for deletes.
-    // abstract Notification getProgressNotification(long bytesCopied);
+    abstract Notification getProgressNotification();
     abstract Notification getFailureNotification();
 
     abstract Notification getWarningNotification();
@@ -158,13 +179,21 @@ abstract public class Job implements Runnable {
         }
     }
 
+    final @State int getState() {
+        return mState;
+    }
+
     final void cancel() {
-        mCanceled = true;
+        mState = STATE_CANCELED;
         Metrics.logFileOperationCancelled(service, operationType);
     }
 
     final boolean isCanceled() {
-        return mCanceled;
+        return mState == STATE_CANCELED;
+    }
+
+    final boolean isFinished() {
+        return mState == STATE_CANCELED || mState == STATE_COMPLETED;
     }
 
     final ContentResolver getContentResolver() {
@@ -321,6 +350,5 @@ abstract public class Job implements Runnable {
     interface Listener {
         void onStart(Job job);
         void onFinished(Job job);
-        void onProgress(CopyJob job);
     }
 }