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