From 4a7aba23be83a3d158f6b157c652f00a6e88de4f Mon Sep 17 00:00:00 2001 From: "Garfield, Tan" Date: Thu, 9 Jun 2016 12:04:22 -0700 Subject: [PATCH] Poll jobs' status to update notifications. Bug: 27249491 Change-Id: I8912c781582af1789c8f76dea06879a3dde75d34 --- packages/DocumentsUI/res/values/strings.xml | 2 + .../android/documentsui/services/CopyJob.java | 47 ++++---- .../documentsui/services/DeleteJob.java | 20 ++++ .../services/FileOperationService.java | 112 ++++++++++++++---- .../com/android/documentsui/services/Job.java | 40 ++++++- .../services/FileOperationServiceTest.java | 61 ++++++++-- .../android/documentsui/services/TestJob.java | 26 +++- .../documentsui/services/TestJobListener.java | 5 - .../documentsui/testing/TestHandler.java | 64 ++++++++++ .../documentsui/testing/TestTimer.java | 38 ++++-- 10 files changed, 331 insertions(+), 84 deletions(-) create mode 100644 packages/DocumentsUI/tests/src/com/android/documentsui/testing/TestHandler.java diff --git a/packages/DocumentsUI/res/values/strings.xml b/packages/DocumentsUI/res/values/strings.xml index be21b55c4066e..f7124e666a205 100644 --- a/packages/DocumentsUI/res/values/strings.xml +++ b/packages/DocumentsUI/res/values/strings.xml @@ -157,6 +157,8 @@ Preparing for move\u2026 Preparing for delete\u2026 + + %1$d / %2$d Couldn\u2019t copy %1$d file diff --git a/packages/DocumentsUI/src/com/android/documentsui/services/CopyJob.java b/packages/DocumentsUI/src/com/android/documentsui/services/CopyJob.java index f10af4378c219..d6f2e5beeb09c 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 mSrcs; final ArrayList 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 8f451623cf72b..e9bdd2cfa92d4 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 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 @@ -68,6 +70,17 @@ final class DeleteJob extends Job { return getSetupNotification(service.getString(R.string.delete_preparing)); } + @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( @@ -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 36a279b347c6a..a3bff90d7b7d2 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 unfinished = executor.shutdownNow(); + + List unfinishedCopies = executor.shutdownNow(); + List unfinishedDeletions = deletionExecutor.shutdownNow(); + List 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. + * + *

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 b8f8fba72d62d..fc3a73171add2 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 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); } } diff --git a/packages/DocumentsUI/tests/src/com/android/documentsui/services/FileOperationServiceTest.java b/packages/DocumentsUI/tests/src/com/android/documentsui/services/FileOperationServiceTest.java index f385776cad4cb..9d6e1d7e26e84 100644 --- a/packages/DocumentsUI/tests/src/com/android/documentsui/services/FileOperationServiceTest.java +++ b/packages/DocumentsUI/tests/src/com/android/documentsui/services/FileOperationServiceTest.java @@ -20,6 +20,7 @@ import static com.android.documentsui.services.FileOperationService.OPERATION_CO import static com.android.documentsui.services.FileOperationService.OPERATION_DELETE; import static com.android.documentsui.services.FileOperations.createBaseIntent; import static com.android.documentsui.services.FileOperations.createJobId; + import static com.google.android.collect.Lists.newArrayList; import android.content.Context; @@ -31,13 +32,11 @@ import android.test.suitebuilder.annotation.MediumTest; import com.android.documentsui.model.DocumentInfo; import com.android.documentsui.model.DocumentStack; import com.android.documentsui.services.Job.Listener; +import com.android.documentsui.testing.TestHandler; import java.util.ArrayList; import java.util.List; -/** - * TODO: Test progress updates. - */ @MediumTest public class FileOperationServiceTest extends ServiceTestCase { @@ -49,6 +48,7 @@ public class FileOperationServiceTest extends ServiceTestCase files, DocumentInfo dest) @@ -217,10 +245,21 @@ public class FileOperationServiceTest extends ServiceTestCase copyJobs = new ArrayList<>(); - final List deleteJobs = new ArrayList<>(); + private final List copyJobs = new ArrayList<>(); + private final List deleteJobs = new ArrayList<>(); + + private Runnable mJobRunnable = () -> { + // The following statement is executed concurrently to Job.start() in real situation. + // Call it in TestJob.start() to mimic this behavior. + mHandler.dispatchNextMessage(); + }; void assertAllCopyJobsStarted() { for (TestJob job : copyJobs) { @@ -258,7 +297,8 @@ public class FileOperationServiceTest extends ServiceTestCase iter = mTaskList.listIterator(0); - while (iter.hasNext()) { - if (iter.next().mExecuteTime >= executeTime) { - break; - } - } - iter.add(testTimerTask); + scheduleAtTime(task, executeTime); } @Override @@ -106,6 +109,19 @@ public class TestTimer extends Timer { throw new UnsupportedOperationException(); } + public void scheduleAtTime(TimerTask task, long executeTime) { + Task testTimerTask = (Task) task; + testTimerTask.mExecuteTime = executeTime; + + ListIterator iter = mTaskList.listIterator(0); + while (iter.hasNext()) { + if (iter.next().mExecuteTime >= executeTime) { + break; + } + } + iter.add(testTimerTask); + } + public static class Task extends TimerTask { private boolean mIsCancelled; private long mExecuteTime;