PerformFullTransportBackupTask.java revision d6c00c711000aa70db51f46b48a86c2884e91b15
1/*
2 * Copyright (C) 2017 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 *      http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License
15 */
16
17package com.android.server.backup.fullbackup;
18
19import android.app.IBackupAgent;
20import android.app.backup.BackupManager;
21import android.app.backup.BackupManagerMonitor;
22import android.app.backup.BackupProgress;
23import android.app.backup.BackupTransport;
24import android.app.backup.IBackupManagerMonitor;
25import android.app.backup.IBackupObserver;
26import android.app.backup.IFullBackupRestoreObserver;
27import android.content.pm.PackageInfo;
28import android.content.pm.PackageManager;
29import android.content.pm.PackageManager.NameNotFoundException;
30import android.os.ParcelFileDescriptor;
31import android.os.RemoteException;
32import android.util.EventLog;
33import android.util.Log;
34import android.util.Slog;
35
36import com.android.internal.backup.IBackupTransport;
37import com.android.server.EventLogTags;
38import com.android.server.backup.BackupRestoreTask;
39import com.android.server.backup.FullBackupJob;
40import com.android.server.backup.RefactoredBackupManagerService;
41import com.android.server.backup.internal.Operation;
42
43import java.io.FileInputStream;
44import java.io.FileOutputStream;
45import java.io.IOException;
46import java.util.ArrayList;
47import java.util.concurrent.CountDownLatch;
48import java.util.concurrent.TimeUnit;
49import java.util.concurrent.atomic.AtomicLong;
50
51/**
52 * Full backup task extension used for transport-oriented operation.
53 *
54 * Flow:
55 * For each requested package:
56 *     - Spin off a new SinglePackageBackupRunner (mBackupRunner) for the current package.
57 *     - Wait until preflight is complete. (mBackupRunner.getPreflightResultBlocking())
58 *     - If preflight data size is within limit, start reading data from agent pipe and writing
59 *       to transport pipe. While there is data to send, call transport.sendBackupData(int) to
60 *       tell the transport how many bytes to expect on its pipe.
61 *     - After sending all data, call transport.finishBackup() if things went well. And
62 *       transport.cancelFullBackup() otherwise.
63 *
64 * Interactions with mCurrentOperations:
65 *     - An entry for this object is added to mCurrentOperations for the entire lifetime of this
66 *       object. Used to cancel the operation.
67 *     - SinglePackageBackupRunner and SinglePackageBackupPreflight will put ephemeral entries
68 *       to get timeouts or operation complete callbacks.
69 *
70 * Handling cancels:
71 *     - The contract we provide is that the task won't interact with the transport after
72 *       handleCancel() is done executing.
73 *     - This task blocks at 3 points: 1. Preflight result check 2. Reading on agent side pipe
74 *       and 3. Get backup result from mBackupRunner.
75 *     - Bubbling up handleCancel to mBackupRunner handles all 3: 1. Calls handleCancel on the
76 *       preflight operation which counts down on the preflight latch. 2. Tears down the agent,
77 *       so read() returns -1. 3. Notifies mCurrentOpLock which unblocks
78 *       mBackupRunner.getBackupResultBlocking().
79 */
80public class PerformFullTransportBackupTask extends FullBackupTask implements BackupRestoreTask {
81    private static final String TAG = "PFTBT";
82
83    private RefactoredBackupManagerService backupManagerService;
84    private final Object mCancelLock = new Object();
85
86    ArrayList<PackageInfo> mPackages;
87    PackageInfo mCurrentPackage;
88    boolean mUpdateSchedule;
89    CountDownLatch mLatch;
90    FullBackupJob mJob;             // if a scheduled job needs to be finished afterwards
91    IBackupObserver mBackupObserver;
92    IBackupManagerMonitor mMonitor;
93    boolean mUserInitiated;
94    private volatile IBackupTransport mTransport;
95    SinglePackageBackupRunner mBackupRunner;
96    private final int mBackupRunnerOpToken;
97
98    // This is true when a backup operation for some package is in progress.
99    private volatile boolean mIsDoingBackup;
100    private volatile boolean mCancelAll;
101    private final int mCurrentOpToken;
102
103    public PerformFullTransportBackupTask(RefactoredBackupManagerService backupManagerService,
104            IFullBackupRestoreObserver observer,
105            String[] whichPackages, boolean updateSchedule,
106            FullBackupJob runningJob, CountDownLatch latch, IBackupObserver backupObserver,
107            IBackupManagerMonitor monitor, boolean userInitiated) {
108        super(observer);
109        this.backupManagerService = backupManagerService;
110        mUpdateSchedule = updateSchedule;
111        mLatch = latch;
112        mJob = runningJob;
113        mPackages = new ArrayList<>(whichPackages.length);
114        mBackupObserver = backupObserver;
115        mMonitor = monitor;
116        mUserInitiated = userInitiated;
117        mCurrentOpToken = backupManagerService.generateRandomIntegerToken();
118        mBackupRunnerOpToken = backupManagerService.generateRandomIntegerToken();
119
120        if (backupManagerService.isBackupOperationInProgress()) {
121            if (RefactoredBackupManagerService.DEBUG) {
122                Slog.d(TAG, "Skipping full backup. A backup is already in progress.");
123            }
124            mCancelAll = true;
125            return;
126        }
127
128        registerTask();
129
130        for (String pkg : whichPackages) {
131            try {
132                PackageInfo info = backupManagerService.getPackageManager().getPackageInfo(pkg,
133                        PackageManager.GET_SIGNATURES);
134                mCurrentPackage = info;
135                if (!RefactoredBackupManagerService.appIsEligibleForBackup(info.applicationInfo)) {
136                    // Cull any packages that have indicated that backups are not permitted,
137                    // that run as system-domain uids but do not define their own backup agents,
138                    // as well as any explicit mention of the 'special' shared-storage agent
139                    // package (we handle that one at the end).
140                    if (RefactoredBackupManagerService.MORE_DEBUG) {
141                        Slog.d(TAG, "Ignoring ineligible package " + pkg);
142                    }
143                    mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
144                            BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_INELIGIBLE,
145                            mCurrentPackage,
146                            BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
147                            null);
148                    RefactoredBackupManagerService.sendBackupOnPackageResult(mBackupObserver, pkg,
149                            BackupManager.ERROR_BACKUP_NOT_ALLOWED);
150                    continue;
151                } else if (!RefactoredBackupManagerService.appGetsFullBackup(info)) {
152                    // Cull any packages that are found in the queue but now aren't supposed
153                    // to get full-data backup operations.
154                    if (RefactoredBackupManagerService.MORE_DEBUG) {
155                        Slog.d(TAG, "Ignoring full-data backup of key/value participant "
156                                + pkg);
157                    }
158                    mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
159                            BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_KEY_VALUE_PARTICIPANT,
160                            mCurrentPackage,
161                            BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
162                            null);
163                    RefactoredBackupManagerService.sendBackupOnPackageResult(mBackupObserver, pkg,
164                            BackupManager.ERROR_BACKUP_NOT_ALLOWED);
165                    continue;
166                } else if (RefactoredBackupManagerService.appIsStopped(info.applicationInfo)) {
167                    // Cull any packages in the 'stopped' state: they've either just been
168                    // installed or have explicitly been force-stopped by the user.  In both
169                    // cases we do not want to launch them for backup.
170                    if (RefactoredBackupManagerService.MORE_DEBUG) {
171                        Slog.d(TAG, "Ignoring stopped package " + pkg);
172                    }
173                    mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
174                            BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_STOPPED,
175                            mCurrentPackage,
176                            BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
177                            null);
178                    RefactoredBackupManagerService.sendBackupOnPackageResult(mBackupObserver, pkg,
179                            BackupManager.ERROR_BACKUP_NOT_ALLOWED);
180                    continue;
181                }
182                mPackages.add(info);
183            } catch (NameNotFoundException e) {
184                Slog.i(TAG, "Requested package " + pkg + " not found; ignoring");
185                mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
186                        BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_NOT_FOUND,
187                        mCurrentPackage,
188                        BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
189                        null);
190            }
191        }
192    }
193
194    private void registerTask() {
195        synchronized (backupManagerService.getCurrentOpLock()) {
196            Slog.d(TAG, "backupmanager pftbt token=" + Integer.toHexString(mCurrentOpToken));
197            backupManagerService.getCurrentOperations().put(mCurrentOpToken, new Operation(
198                    RefactoredBackupManagerService.OP_PENDING, this,
199                    RefactoredBackupManagerService.OP_TYPE_BACKUP));
200        }
201    }
202
203    public void unregisterTask() {
204        backupManagerService.removeOperation(mCurrentOpToken);
205    }
206
207    @Override
208    public void execute() {
209        // Nothing to do.
210    }
211
212    @Override
213    public void handleCancel(boolean cancelAll) {
214        synchronized (mCancelLock) {
215            // We only support 'cancelAll = true' case for this task. Cancelling of a single package
216
217            // due to timeout is handled by SinglePackageBackupRunner and
218            // SinglePackageBackupPreflight.
219
220            if (!cancelAll) {
221                Slog.wtf(TAG, "Expected cancelAll to be true.");
222            }
223
224            if (mCancelAll) {
225                Slog.d(TAG, "Ignoring duplicate cancel call.");
226                return;
227            }
228
229            mCancelAll = true;
230            if (mIsDoingBackup) {
231                backupManagerService.handleCancel(mBackupRunnerOpToken, cancelAll);
232                try {
233                    mTransport.cancelFullBackup();
234                } catch (RemoteException e) {
235                    Slog.w(TAG, "Error calling cancelFullBackup() on transport: " + e);
236                    // Can't do much.
237                }
238            }
239        }
240    }
241
242    @Override
243    public void operationComplete(long result) {
244        // Nothing to do.
245    }
246
247    @Override
248    public void run() {
249
250        // data from the app, passed to us for bridging to the transport
251        ParcelFileDescriptor[] enginePipes = null;
252
253        // Pipe through which we write data to the transport
254        ParcelFileDescriptor[] transportPipes = null;
255
256        long backoff = 0;
257        int backupRunStatus = BackupManager.SUCCESS;
258
259        try {
260            if (!backupManagerService.isEnabled() || !backupManagerService.isProvisioned()) {
261                // Backups are globally disabled, so don't proceed.
262                if (RefactoredBackupManagerService.DEBUG) {
263                    Slog.i(TAG, "full backup requested but enabled=" + backupManagerService
264                            .isEnabled()
265                            + " provisioned=" + backupManagerService.isProvisioned() + "; ignoring");
266                }
267                int monitoringEvent;
268                if (!backupManagerService.isEnabled()) {
269                    monitoringEvent = BackupManagerMonitor.LOG_EVENT_ID_BACKUP_DISABLED;
270                } else {
271                    monitoringEvent = BackupManagerMonitor.LOG_EVENT_ID_DEVICE_NOT_PROVISIONED;
272                }
273                mMonitor = RefactoredBackupManagerService
274                        .monitorEvent(mMonitor, monitoringEvent, null,
275                                BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
276                                null);
277                mUpdateSchedule = false;
278                backupRunStatus = BackupManager.ERROR_BACKUP_NOT_ALLOWED;
279                return;
280            }
281
282            mTransport = backupManagerService.getTransportManager().getCurrentTransportBinder();
283            if (mTransport == null) {
284                Slog.w(TAG, "Transport not present; full data backup not performed");
285                backupRunStatus = BackupManager.ERROR_TRANSPORT_ABORTED;
286                mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
287                        BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_TRANSPORT_NOT_PRESENT,
288                        mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT,
289                        null);
290                return;
291            }
292
293            // Set up to send data to the transport
294            final int N = mPackages.size();
295            final byte[] buffer = new byte[8192];
296            for (int i = 0; i < N; i++) {
297                PackageInfo currentPackage = mPackages.get(i);
298                String packageName = currentPackage.packageName;
299                if (RefactoredBackupManagerService.DEBUG) {
300                    Slog.i(TAG, "Initiating full-data transport backup of " + packageName
301                            + " token: " + mCurrentOpToken);
302                }
303                EventLog.writeEvent(EventLogTags.FULL_BACKUP_PACKAGE, packageName);
304
305                transportPipes = ParcelFileDescriptor.createPipe();
306
307                // Tell the transport the data's coming
308                int flags = mUserInitiated ? BackupTransport.FLAG_USER_INITIATED : 0;
309                int backupPackageStatus;
310                long quota = Long.MAX_VALUE;
311                synchronized (mCancelLock) {
312                    if (mCancelAll) {
313                        break;
314                    }
315                    backupPackageStatus = mTransport.performFullBackup(currentPackage,
316                            transportPipes[0], flags);
317
318                    if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
319                        quota = mTransport.getBackupQuota(currentPackage.packageName,
320                                true /* isFullBackup */);
321                        // Now set up the backup engine / data source end of things
322                        enginePipes = ParcelFileDescriptor.createPipe();
323                        mBackupRunner =
324                                new SinglePackageBackupRunner(enginePipes[1], currentPackage,
325                                        mTransport, quota, mBackupRunnerOpToken);
326                        // The runner dup'd the pipe half, so we close it here
327                        enginePipes[1].close();
328                        enginePipes[1] = null;
329
330                        mIsDoingBackup = true;
331                    }
332                }
333                if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
334
335                    // The transport has its own copy of the read end of the pipe,
336                    // so close ours now
337                    transportPipes[0].close();
338                    transportPipes[0] = null;
339
340                    // Spin off the runner to fetch the app's data and pipe it
341                    // into the engine pipes
342                    (new Thread(mBackupRunner, "package-backup-bridge")).start();
343
344                    // Read data off the engine pipe and pass it to the transport
345                    // pipe until we hit EOD on the input stream.  We do not take
346                    // close() responsibility for these FDs into these stream wrappers.
347                    FileInputStream in = new FileInputStream(
348                            enginePipes[0].getFileDescriptor());
349                    FileOutputStream out = new FileOutputStream(
350                            transportPipes[1].getFileDescriptor());
351                    long totalRead = 0;
352                    final long preflightResult = mBackupRunner.getPreflightResultBlocking();
353                    // Preflight result is negative if some error happened on preflight.
354                    if (preflightResult < 0) {
355                        if (RefactoredBackupManagerService.MORE_DEBUG) {
356                            Slog.d(TAG, "Backup error after preflight of package "
357                                    + packageName + ": " + preflightResult
358                                    + ", not running backup.");
359                        }
360                        mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
361                                BackupManagerMonitor.LOG_EVENT_ID_ERROR_PREFLIGHT,
362                                mCurrentPackage,
363                                BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
364                                backupManagerService.putMonitoringExtra(null,
365                                        BackupManagerMonitor.EXTRA_LOG_PREFLIGHT_ERROR,
366                                        preflightResult));
367                        backupPackageStatus = (int) preflightResult;
368                    } else {
369                        int nRead = 0;
370                        do {
371                            nRead = in.read(buffer);
372                            if (RefactoredBackupManagerService.MORE_DEBUG) {
373                                Slog.v(TAG, "in.read(buffer) from app: " + nRead);
374                            }
375                            if (nRead > 0) {
376                                out.write(buffer, 0, nRead);
377                                synchronized (mCancelLock) {
378                                    if (!mCancelAll) {
379                                        backupPackageStatus = mTransport.sendBackupData(nRead);
380                                    }
381                                }
382                                totalRead += nRead;
383                                if (mBackupObserver != null && preflightResult > 0) {
384                                    RefactoredBackupManagerService
385                                            .sendBackupOnUpdate(mBackupObserver, packageName,
386                                                    new BackupProgress(preflightResult, totalRead));
387                                }
388                            }
389                        } while (nRead > 0
390                                && backupPackageStatus == BackupTransport.TRANSPORT_OK);
391                        // Despite preflight succeeded, package still can hit quota on flight.
392                        if (backupPackageStatus == BackupTransport.TRANSPORT_QUOTA_EXCEEDED) {
393                            Slog.w(TAG, "Package hit quota limit in-flight " + packageName
394                                    + ": " + totalRead + " of " + quota);
395                            mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
396                                    BackupManagerMonitor.LOG_EVENT_ID_QUOTA_HIT_PREFLIGHT,
397                                    mCurrentPackage,
398                                    BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT,
399                                    null);
400                            mBackupRunner.sendQuotaExceeded(totalRead, quota);
401                        }
402                    }
403
404                    final int backupRunnerResult = mBackupRunner.getBackupResultBlocking();
405
406                    synchronized (mCancelLock) {
407                        mIsDoingBackup = false;
408                        // If mCancelCurrent is true, we have already called cancelFullBackup().
409                        if (!mCancelAll) {
410                            if (backupRunnerResult == BackupTransport.TRANSPORT_OK) {
411                                // If we were otherwise in a good state, now interpret the final
412                                // result based on what finishBackup() returns.  If we're in a
413                                // failure case already, preserve that result and ignore whatever
414                                // finishBackup() reports.
415                                final int finishResult = mTransport.finishBackup();
416                                if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
417                                    backupPackageStatus = finishResult;
418                                }
419                            } else {
420                                mTransport.cancelFullBackup();
421                            }
422                        }
423                    }
424
425                    // A transport-originated error here means that we've hit an error that the
426                    // runner doesn't know about, so it's still moving data but we're pulling the
427                    // rug out from under it.  Don't ask for its result:  we already know better
428                    // and we'll hang if we block waiting for it, since it relies on us to
429                    // read back the data it's writing into the engine.  Just proceed with
430                    // a graceful failure.  The runner/engine mechanism will tear itself
431                    // down cleanly when we close the pipes from this end.  Transport-level
432                    // errors take precedence over agent/app-specific errors for purposes of
433                    // determining our course of action.
434                    if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
435                        // We still could fail in backup runner thread.
436                        if (backupRunnerResult != BackupTransport.TRANSPORT_OK) {
437                            // If there was an error in runner thread and
438                            // not TRANSPORT_ERROR here, overwrite it.
439                            backupPackageStatus = backupRunnerResult;
440                        }
441                    } else {
442                        if (RefactoredBackupManagerService.MORE_DEBUG) {
443                            Slog.i(TAG, "Transport-level failure; cancelling agent work");
444                        }
445                    }
446
447                    if (RefactoredBackupManagerService.MORE_DEBUG) {
448                        Slog.i(TAG, "Done delivering backup data: result="
449                                + backupPackageStatus);
450                    }
451
452                    if (backupPackageStatus != BackupTransport.TRANSPORT_OK) {
453                        Slog.e(TAG, "Error " + backupPackageStatus + " backing up "
454                                + packageName);
455                    }
456
457                    // Also ask the transport how long it wants us to wait before
458                    // moving on to the next package, if any.
459                    backoff = mTransport.requestFullBackupTime();
460                    if (RefactoredBackupManagerService.DEBUG_SCHEDULING) {
461                        Slog.i(TAG, "Transport suggested backoff=" + backoff);
462                    }
463
464                }
465
466                // Roll this package to the end of the backup queue if we're
467                // in a queue-driven mode (regardless of success/failure)
468                if (mUpdateSchedule) {
469                    backupManagerService.enqueueFullBackup(packageName, System.currentTimeMillis());
470                }
471
472                if (backupPackageStatus == BackupTransport.TRANSPORT_PACKAGE_REJECTED) {
473                    RefactoredBackupManagerService
474                            .sendBackupOnPackageResult(mBackupObserver, packageName,
475                                    BackupManager.ERROR_TRANSPORT_PACKAGE_REJECTED);
476                    if (RefactoredBackupManagerService.DEBUG) {
477                        Slog.i(TAG, "Transport rejected backup of " + packageName
478                                + ", skipping");
479                    }
480                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_AGENT_FAILURE, packageName,
481                            "transport rejected");
482                    // Do nothing, clean up, and continue looping.
483                } else if (backupPackageStatus == BackupTransport.TRANSPORT_QUOTA_EXCEEDED) {
484                    RefactoredBackupManagerService
485                            .sendBackupOnPackageResult(mBackupObserver, packageName,
486                                    BackupManager.ERROR_TRANSPORT_QUOTA_EXCEEDED);
487                    if (RefactoredBackupManagerService.DEBUG) {
488                        Slog.i(TAG, "Transport quota exceeded for package: " + packageName);
489                        EventLog.writeEvent(EventLogTags.FULL_BACKUP_QUOTA_EXCEEDED,
490                                packageName);
491                    }
492                    // Do nothing, clean up, and continue looping.
493                } else if (backupPackageStatus == BackupTransport.AGENT_ERROR) {
494                    RefactoredBackupManagerService
495                            .sendBackupOnPackageResult(mBackupObserver, packageName,
496                                    BackupManager.ERROR_AGENT_FAILURE);
497                    Slog.w(TAG, "Application failure for package: " + packageName);
498                    EventLog.writeEvent(EventLogTags.BACKUP_AGENT_FAILURE, packageName);
499                    backupManagerService.tearDownAgentAndKill(currentPackage.applicationInfo);
500                    // Do nothing, clean up, and continue looping.
501                } else if (backupPackageStatus == BackupManager.ERROR_BACKUP_CANCELLED) {
502                    RefactoredBackupManagerService
503                            .sendBackupOnPackageResult(mBackupObserver, packageName,
504                                    BackupManager.ERROR_BACKUP_CANCELLED);
505                    Slog.w(TAG, "Backup cancelled. package=" + packageName +
506                            ", cancelAll=" + mCancelAll);
507                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_CANCELLED, packageName);
508                    backupManagerService.tearDownAgentAndKill(currentPackage.applicationInfo);
509                    // Do nothing, clean up, and continue looping.
510                } else if (backupPackageStatus != BackupTransport.TRANSPORT_OK) {
511                    RefactoredBackupManagerService
512                            .sendBackupOnPackageResult(mBackupObserver, packageName,
513                                    BackupManager.ERROR_TRANSPORT_ABORTED);
514                    Slog.w(TAG, "Transport failed; aborting backup: " + backupPackageStatus);
515                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_TRANSPORT_FAILURE);
516                    // Abort entire backup pass.
517                    backupRunStatus = BackupManager.ERROR_TRANSPORT_ABORTED;
518                    return;
519                } else {
520                    // Success!
521                    RefactoredBackupManagerService
522                            .sendBackupOnPackageResult(mBackupObserver, packageName,
523                                    BackupManager.SUCCESS);
524                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_SUCCESS, packageName);
525                    backupManagerService.logBackupComplete(packageName);
526                }
527                cleanUpPipes(transportPipes);
528                cleanUpPipes(enginePipes);
529                if (currentPackage.applicationInfo != null) {
530                    Slog.i(TAG, "Unbinding agent in " + packageName);
531                    backupManagerService.addBackupTrace("unbinding " + packageName);
532                    try {
533                        backupManagerService.getActivityManager().unbindBackupAgent(
534                                currentPackage.applicationInfo);
535                    } catch (RemoteException e) { /* can't happen; activity manager is local */ }
536                }
537            }
538        } catch (Exception e) {
539            backupRunStatus = BackupManager.ERROR_TRANSPORT_ABORTED;
540            Slog.w(TAG, "Exception trying full transport backup", e);
541            mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
542                    BackupManagerMonitor.LOG_EVENT_ID_EXCEPTION_FULL_BACKUP,
543                    mCurrentPackage,
544                    BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
545                    backupManagerService.putMonitoringExtra(null,
546                            BackupManagerMonitor.EXTRA_LOG_EXCEPTION_FULL_BACKUP,
547                            Log.getStackTraceString(e)));
548
549        } finally {
550
551            if (mCancelAll) {
552                backupRunStatus = BackupManager.ERROR_BACKUP_CANCELLED;
553            }
554
555            if (RefactoredBackupManagerService.DEBUG) {
556                Slog.i(TAG, "Full backup completed with status: " + backupRunStatus);
557            }
558            RefactoredBackupManagerService.sendBackupFinished(mBackupObserver, backupRunStatus);
559
560            cleanUpPipes(transportPipes);
561            cleanUpPipes(enginePipes);
562
563            unregisterTask();
564
565            if (mJob != null) {
566                mJob.finishBackupPass();
567            }
568
569            synchronized (backupManagerService.getQueueLock()) {
570                backupManagerService.setRunningFullBackupTask(null);
571            }
572
573            mLatch.countDown();
574
575            // Now that we're actually done with schedule-driven work, reschedule
576            // the next pass based on the new queue state.
577            if (mUpdateSchedule) {
578                backupManagerService.scheduleNextFullBackupJob(backoff);
579            }
580
581            Slog.i(RefactoredBackupManagerService.TAG, "Full data backup pass finished.");
582            backupManagerService.getWakelock().release();
583        }
584    }
585
586    void cleanUpPipes(ParcelFileDescriptor[] pipes) {
587        if (pipes != null) {
588            if (pipes[0] != null) {
589                ParcelFileDescriptor fd = pipes[0];
590                pipes[0] = null;
591                try {
592                    fd.close();
593                } catch (IOException e) {
594                    Slog.w(TAG, "Unable to close pipe!");
595                }
596            }
597            if (pipes[1] != null) {
598                ParcelFileDescriptor fd = pipes[1];
599                pipes[1] = null;
600                try {
601                    fd.close();
602                } catch (IOException e) {
603                    Slog.w(TAG, "Unable to close pipe!");
604                }
605            }
606        }
607    }
608
609    // Run the backup and pipe it back to the given socket -- expects to run on
610    // a standalone thread.  The  runner owns this half of the pipe, and closes
611    // it to indicate EOD to the other end.
612    class SinglePackageBackupPreflight implements BackupRestoreTask, FullBackupPreflight {
613        final AtomicLong mResult = new AtomicLong(BackupTransport.AGENT_ERROR);
614        final CountDownLatch mLatch = new CountDownLatch(1);
615        final IBackupTransport mTransport;
616        final long mQuota;
617        private final int mCurrentOpToken;
618
619        SinglePackageBackupPreflight(IBackupTransport transport, long quota, int currentOpToken) {
620            mTransport = transport;
621            mQuota = quota;
622            mCurrentOpToken = currentOpToken;
623        }
624
625        @Override
626        public int preflightFullBackup(PackageInfo pkg, IBackupAgent agent) {
627            int result;
628            try {
629                backupManagerService
630                        .prepareOperationTimeout(mCurrentOpToken,
631                                RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
632                                this, RefactoredBackupManagerService.OP_TYPE_BACKUP_WAIT);
633                backupManagerService.addBackupTrace("preflighting");
634                if (RefactoredBackupManagerService.MORE_DEBUG) {
635                    Slog.d(TAG, "Preflighting full payload of " + pkg.packageName);
636                }
637                agent.doMeasureFullBackup(mQuota, mCurrentOpToken,
638                        backupManagerService.getBackupManagerBinder());
639
640                // Now wait to get our result back.  If this backstop timeout is reached without
641                // the latch being thrown, flow will continue as though a result or "normal"
642                // timeout had been produced.  In case of a real backstop timeout, mResult
643                // will still contain the value it was constructed with, AGENT_ERROR, which
644                // intentionaly falls into the "just report failure" code.
645                mLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
646                        TimeUnit.MILLISECONDS);
647
648                long totalSize = mResult.get();
649                // If preflight timed out, mResult will contain error code as int.
650                if (totalSize < 0) {
651                    return (int) totalSize;
652                }
653                if (RefactoredBackupManagerService.MORE_DEBUG) {
654                    Slog.v(TAG, "Got preflight response; size=" + totalSize);
655                }
656
657                result = mTransport.checkFullBackupSize(totalSize);
658                if (result == BackupTransport.TRANSPORT_QUOTA_EXCEEDED) {
659                    if (RefactoredBackupManagerService.MORE_DEBUG) {
660                        Slog.d(TAG, "Package hit quota limit on preflight " +
661                                pkg.packageName + ": " + totalSize + " of " + mQuota);
662                    }
663                    agent.doQuotaExceeded(totalSize, mQuota);
664                }
665            } catch (Exception e) {
666                Slog.w(TAG, "Exception preflighting " + pkg.packageName + ": " + e.getMessage());
667                result = BackupTransport.AGENT_ERROR;
668            }
669            return result;
670        }
671
672        @Override
673        public void execute() {
674            // Unused.
675        }
676
677        @Override
678        public void operationComplete(long result) {
679            // got the callback, and our preflightFullBackup() method is waiting for the result
680            if (RefactoredBackupManagerService.MORE_DEBUG) {
681                Slog.i(TAG, "Preflight op complete, result=" + result);
682            }
683            mResult.set(result);
684            mLatch.countDown();
685            backupManagerService.removeOperation(mCurrentOpToken);
686        }
687
688        @Override
689        public void handleCancel(boolean cancelAll) {
690            if (RefactoredBackupManagerService.MORE_DEBUG) {
691                Slog.i(TAG, "Preflight cancelled; failing");
692            }
693            mResult.set(BackupTransport.AGENT_ERROR);
694            mLatch.countDown();
695            backupManagerService.removeOperation(mCurrentOpToken);
696        }
697
698        @Override
699        public long getExpectedSizeOrErrorCode() {
700            try {
701                mLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
702                        TimeUnit.MILLISECONDS);
703                return mResult.get();
704            } catch (InterruptedException e) {
705                return BackupTransport.NO_MORE_DATA;
706            }
707        }
708    }
709
710    class SinglePackageBackupRunner implements Runnable, BackupRestoreTask {
711        final ParcelFileDescriptor mOutput;
712        final PackageInfo mTarget;
713        final SinglePackageBackupPreflight mPreflight;
714        final CountDownLatch mPreflightLatch;
715        final CountDownLatch mBackupLatch;
716        private final int mCurrentOpToken;
717        private final int mEphemeralToken;
718        private FullBackupEngine mEngine;
719        private volatile int mPreflightResult;
720        private volatile int mBackupResult;
721        private final long mQuota;
722        private volatile boolean mIsCancelled;
723
724        SinglePackageBackupRunner(ParcelFileDescriptor output, PackageInfo target,
725                IBackupTransport transport, long quota, int currentOpToken) throws IOException {
726            mOutput = ParcelFileDescriptor.dup(output.getFileDescriptor());
727            mTarget = target;
728            mCurrentOpToken = currentOpToken;
729            mEphemeralToken = backupManagerService.generateRandomIntegerToken();
730            mPreflight = new SinglePackageBackupPreflight(transport, quota, mEphemeralToken);
731            mPreflightLatch = new CountDownLatch(1);
732            mBackupLatch = new CountDownLatch(1);
733            mPreflightResult = BackupTransport.AGENT_ERROR;
734            mBackupResult = BackupTransport.AGENT_ERROR;
735            mQuota = quota;
736            registerTask();
737        }
738
739        void registerTask() {
740            synchronized (backupManagerService.getCurrentOpLock()) {
741                backupManagerService.getCurrentOperations().put(mCurrentOpToken, new Operation(
742                        RefactoredBackupManagerService.OP_PENDING, this,
743                        RefactoredBackupManagerService.OP_TYPE_BACKUP_WAIT));
744            }
745        }
746
747        void unregisterTask() {
748            synchronized (backupManagerService.getCurrentOpLock()) {
749                backupManagerService.getCurrentOperations().remove(mCurrentOpToken);
750            }
751        }
752
753        @Override
754        public void run() {
755            FileOutputStream out = new FileOutputStream(mOutput.getFileDescriptor());
756            mEngine = new FullBackupEngine(backupManagerService, out, mPreflight, mTarget, false,
757                    this, mQuota, mCurrentOpToken);
758            try {
759                try {
760                    if (!mIsCancelled) {
761                        mPreflightResult = mEngine.preflightCheck();
762                    }
763                } finally {
764                    mPreflightLatch.countDown();
765                }
766                // If there is no error on preflight, continue backup.
767                if (mPreflightResult == BackupTransport.TRANSPORT_OK) {
768                    if (!mIsCancelled) {
769                        mBackupResult = mEngine.backupOnePackage();
770                    }
771                }
772            } catch (Exception e) {
773                Slog.e(TAG, "Exception during full package backup of " + mTarget.packageName);
774            } finally {
775                unregisterTask();
776                mBackupLatch.countDown();
777                try {
778                    mOutput.close();
779                } catch (IOException e) {
780                    Slog.w(TAG, "Error closing transport pipe in runner");
781                }
782            }
783        }
784
785        public void sendQuotaExceeded(final long backupDataBytes, final long quotaBytes) {
786            mEngine.sendQuotaExceeded(backupDataBytes, quotaBytes);
787        }
788
789        // If preflight succeeded, returns positive number - preflight size,
790        // otherwise return negative error code.
791        long getPreflightResultBlocking() {
792            try {
793                mPreflightLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
794                        TimeUnit.MILLISECONDS);
795                if (mIsCancelled) {
796                    return BackupManager.ERROR_BACKUP_CANCELLED;
797                }
798                if (mPreflightResult == BackupTransport.TRANSPORT_OK) {
799                    return mPreflight.getExpectedSizeOrErrorCode();
800                } else {
801                    return mPreflightResult;
802                }
803            } catch (InterruptedException e) {
804                return BackupTransport.AGENT_ERROR;
805            }
806        }
807
808        int getBackupResultBlocking() {
809            try {
810                mBackupLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
811                        TimeUnit.MILLISECONDS);
812                if (mIsCancelled) {
813                    return BackupManager.ERROR_BACKUP_CANCELLED;
814                }
815                return mBackupResult;
816            } catch (InterruptedException e) {
817                return BackupTransport.AGENT_ERROR;
818            }
819        }
820
821
822        // BackupRestoreTask interface: specifically, timeout detection
823
824        @Override
825        public void execute() { /* intentionally empty */ }
826
827        @Override
828        public void operationComplete(long result) { /* intentionally empty */ }
829
830        @Override
831        public void handleCancel(boolean cancelAll) {
832            if (RefactoredBackupManagerService.DEBUG) {
833                Slog.w(TAG, "Full backup cancel of " + mTarget.packageName);
834            }
835
836            mMonitor = RefactoredBackupManagerService.monitorEvent(mMonitor,
837                    BackupManagerMonitor.LOG_EVENT_ID_FULL_BACKUP_CANCEL,
838                    mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, null);
839            mIsCancelled = true;
840            // Cancel tasks spun off by this task.
841            backupManagerService.handleCancel(mEphemeralToken, cancelAll);
842            backupManagerService.tearDownAgentAndKill(mTarget.applicationInfo);
843            // Free up everyone waiting on this task and its children.
844            mPreflightLatch.countDown();
845            mBackupLatch.countDown();
846            // We are done with this operation.
847            backupManagerService.removeOperation(mCurrentOpToken);
848        }
849    }
850}
851