PerformFullTransportBackupTask.java revision 0b54d6d92990b8b3193ff5891b4de820ed2f2130
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()
269                            + "; ignoring");
270                }
271                int monitoringEvent;
272                if (!backupManagerService.isEnabled()) {
273                    monitoringEvent = BackupManagerMonitor.LOG_EVENT_ID_BACKUP_DISABLED;
274                } else {
275                    monitoringEvent = BackupManagerMonitor.LOG_EVENT_ID_DEVICE_NOT_PROVISIONED;
276                }
277                mMonitor = BackupManagerMonitorUtils
278                        .monitorEvent(mMonitor, monitoringEvent, null,
279                                BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
280                                null);
281                mUpdateSchedule = false;
282                backupRunStatus = BackupManager.ERROR_BACKUP_NOT_ALLOWED;
283                return;
284            }
285
286            mTransport = backupManagerService.getTransportManager().getCurrentTransportBinder();
287            if (mTransport == null) {
288                Slog.w(TAG, "Transport not present; full data backup not performed");
289                backupRunStatus = BackupManager.ERROR_TRANSPORT_ABORTED;
290                mMonitor = BackupManagerMonitorUtils.monitorEvent(mMonitor,
291                        BackupManagerMonitor.LOG_EVENT_ID_PACKAGE_TRANSPORT_NOT_PRESENT,
292                        mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT,
293                        null);
294                return;
295            }
296
297            // Set up to send data to the transport
298            final int N = mPackages.size();
299            final byte[] buffer = new byte[8192];
300            for (int i = 0; i < N; i++) {
301                PackageInfo currentPackage = mPackages.get(i);
302                String packageName = currentPackage.packageName;
303                if (RefactoredBackupManagerService.DEBUG) {
304                    Slog.i(TAG, "Initiating full-data transport backup of " + packageName
305                            + " token: " + mCurrentOpToken);
306                }
307                EventLog.writeEvent(EventLogTags.FULL_BACKUP_PACKAGE, packageName);
308
309                transportPipes = ParcelFileDescriptor.createPipe();
310
311                // Tell the transport the data's coming
312                int flags = mUserInitiated ? BackupTransport.FLAG_USER_INITIATED : 0;
313                int backupPackageStatus;
314                long quota = Long.MAX_VALUE;
315                synchronized (mCancelLock) {
316                    if (mCancelAll) {
317                        break;
318                    }
319                    backupPackageStatus = mTransport.performFullBackup(currentPackage,
320                            transportPipes[0], flags);
321
322                    if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
323                        quota = mTransport.getBackupQuota(currentPackage.packageName,
324                                true /* isFullBackup */);
325                        // Now set up the backup engine / data source end of things
326                        enginePipes = ParcelFileDescriptor.createPipe();
327                        mBackupRunner =
328                                new SinglePackageBackupRunner(enginePipes[1], currentPackage,
329                                        mTransport, quota, mBackupRunnerOpToken);
330                        // The runner dup'd the pipe half, so we close it here
331                        enginePipes[1].close();
332                        enginePipes[1] = null;
333
334                        mIsDoingBackup = true;
335                    }
336                }
337                if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
338
339                    // The transport has its own copy of the read end of the pipe,
340                    // so close ours now
341                    transportPipes[0].close();
342                    transportPipes[0] = null;
343
344                    // Spin off the runner to fetch the app's data and pipe it
345                    // into the engine pipes
346                    (new Thread(mBackupRunner, "package-backup-bridge")).start();
347
348                    // Read data off the engine pipe and pass it to the transport
349                    // pipe until we hit EOD on the input stream.  We do not take
350                    // close() responsibility for these FDs into these stream wrappers.
351                    FileInputStream in = new FileInputStream(
352                            enginePipes[0].getFileDescriptor());
353                    FileOutputStream out = new FileOutputStream(
354                            transportPipes[1].getFileDescriptor());
355                    long totalRead = 0;
356                    final long preflightResult = mBackupRunner.getPreflightResultBlocking();
357                    // Preflight result is negative if some error happened on preflight.
358                    if (preflightResult < 0) {
359                        if (RefactoredBackupManagerService.MORE_DEBUG) {
360                            Slog.d(TAG, "Backup error after preflight of package "
361                                    + packageName + ": " + preflightResult
362                                    + ", not running backup.");
363                        }
364                        mMonitor = BackupManagerMonitorUtils.monitorEvent(mMonitor,
365                                BackupManagerMonitor.LOG_EVENT_ID_ERROR_PREFLIGHT,
366                                mCurrentPackage,
367                                BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
368                                BackupManagerMonitorUtils.putMonitoringExtra(null,
369                                        BackupManagerMonitor.EXTRA_LOG_PREFLIGHT_ERROR,
370                                        preflightResult));
371                        backupPackageStatus = (int) preflightResult;
372                    } else {
373                        int nRead = 0;
374                        do {
375                            nRead = in.read(buffer);
376                            if (RefactoredBackupManagerService.MORE_DEBUG) {
377                                Slog.v(TAG, "in.read(buffer) from app: " + nRead);
378                            }
379                            if (nRead > 0) {
380                                out.write(buffer, 0, nRead);
381                                synchronized (mCancelLock) {
382                                    if (!mCancelAll) {
383                                        backupPackageStatus = mTransport.sendBackupData(nRead);
384                                    }
385                                }
386                                totalRead += nRead;
387                                if (mBackupObserver != null && preflightResult > 0) {
388                                    BackupObserverUtils
389                                            .sendBackupOnUpdate(mBackupObserver, packageName,
390                                                    new BackupProgress(preflightResult, totalRead));
391                                }
392                            }
393                        } while (nRead > 0
394                                && backupPackageStatus == BackupTransport.TRANSPORT_OK);
395                        // Despite preflight succeeded, package still can hit quota on flight.
396                        if (backupPackageStatus == BackupTransport.TRANSPORT_QUOTA_EXCEEDED) {
397                            Slog.w(TAG, "Package hit quota limit in-flight " + packageName
398                                    + ": " + totalRead + " of " + quota);
399                            mMonitor = BackupManagerMonitorUtils.monitorEvent(mMonitor,
400                                    BackupManagerMonitor.LOG_EVENT_ID_QUOTA_HIT_PREFLIGHT,
401                                    mCurrentPackage,
402                                    BackupManagerMonitor.LOG_EVENT_CATEGORY_TRANSPORT,
403                                    null);
404                            mBackupRunner.sendQuotaExceeded(totalRead, quota);
405                        }
406                    }
407
408                    final int backupRunnerResult = mBackupRunner.getBackupResultBlocking();
409
410                    synchronized (mCancelLock) {
411                        mIsDoingBackup = false;
412                        // If mCancelCurrent is true, we have already called cancelFullBackup().
413                        if (!mCancelAll) {
414                            if (backupRunnerResult == BackupTransport.TRANSPORT_OK) {
415                                // If we were otherwise in a good state, now interpret the final
416                                // result based on what finishBackup() returns.  If we're in a
417                                // failure case already, preserve that result and ignore whatever
418                                // finishBackup() reports.
419                                final int finishResult = mTransport.finishBackup();
420                                if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
421                                    backupPackageStatus = finishResult;
422                                }
423                            } else {
424                                mTransport.cancelFullBackup();
425                            }
426                        }
427                    }
428
429                    // A transport-originated error here means that we've hit an error that the
430                    // runner doesn't know about, so it's still moving data but we're pulling the
431                    // rug out from under it.  Don't ask for its result:  we already know better
432                    // and we'll hang if we block waiting for it, since it relies on us to
433                    // read back the data it's writing into the engine.  Just proceed with
434                    // a graceful failure.  The runner/engine mechanism will tear itself
435                    // down cleanly when we close the pipes from this end.  Transport-level
436                    // errors take precedence over agent/app-specific errors for purposes of
437                    // determining our course of action.
438                    if (backupPackageStatus == BackupTransport.TRANSPORT_OK) {
439                        // We still could fail in backup runner thread.
440                        if (backupRunnerResult != BackupTransport.TRANSPORT_OK) {
441                            // If there was an error in runner thread and
442                            // not TRANSPORT_ERROR here, overwrite it.
443                            backupPackageStatus = backupRunnerResult;
444                        }
445                    } else {
446                        if (RefactoredBackupManagerService.MORE_DEBUG) {
447                            Slog.i(TAG, "Transport-level failure; cancelling agent work");
448                        }
449                    }
450
451                    if (RefactoredBackupManagerService.MORE_DEBUG) {
452                        Slog.i(TAG, "Done delivering backup data: result="
453                                + backupPackageStatus);
454                    }
455
456                    if (backupPackageStatus != BackupTransport.TRANSPORT_OK) {
457                        Slog.e(TAG, "Error " + backupPackageStatus + " backing up "
458                                + packageName);
459                    }
460
461                    // Also ask the transport how long it wants us to wait before
462                    // moving on to the next package, if any.
463                    backoff = mTransport.requestFullBackupTime();
464                    if (RefactoredBackupManagerService.DEBUG_SCHEDULING) {
465                        Slog.i(TAG, "Transport suggested backoff=" + backoff);
466                    }
467
468                }
469
470                // Roll this package to the end of the backup queue if we're
471                // in a queue-driven mode (regardless of success/failure)
472                if (mUpdateSchedule) {
473                    backupManagerService.enqueueFullBackup(packageName, System.currentTimeMillis());
474                }
475
476                if (backupPackageStatus == BackupTransport.TRANSPORT_PACKAGE_REJECTED) {
477                    BackupObserverUtils
478                            .sendBackupOnPackageResult(mBackupObserver, packageName,
479                                    BackupManager.ERROR_TRANSPORT_PACKAGE_REJECTED);
480                    if (RefactoredBackupManagerService.DEBUG) {
481                        Slog.i(TAG, "Transport rejected backup of " + packageName
482                                + ", skipping");
483                    }
484                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_AGENT_FAILURE, packageName,
485                            "transport rejected");
486                    // Do nothing, clean up, and continue looping.
487                } else if (backupPackageStatus == BackupTransport.TRANSPORT_QUOTA_EXCEEDED) {
488                    BackupObserverUtils
489                            .sendBackupOnPackageResult(mBackupObserver, packageName,
490                                    BackupManager.ERROR_TRANSPORT_QUOTA_EXCEEDED);
491                    if (RefactoredBackupManagerService.DEBUG) {
492                        Slog.i(TAG, "Transport quota exceeded for package: " + packageName);
493                        EventLog.writeEvent(EventLogTags.FULL_BACKUP_QUOTA_EXCEEDED,
494                                packageName);
495                    }
496                    // Do nothing, clean up, and continue looping.
497                } else if (backupPackageStatus == BackupTransport.AGENT_ERROR) {
498                    BackupObserverUtils
499                            .sendBackupOnPackageResult(mBackupObserver, packageName,
500                                    BackupManager.ERROR_AGENT_FAILURE);
501                    Slog.w(TAG, "Application failure for package: " + packageName);
502                    EventLog.writeEvent(EventLogTags.BACKUP_AGENT_FAILURE, packageName);
503                    backupManagerService.tearDownAgentAndKill(currentPackage.applicationInfo);
504                    // Do nothing, clean up, and continue looping.
505                } else if (backupPackageStatus == BackupManager.ERROR_BACKUP_CANCELLED) {
506                    BackupObserverUtils
507                            .sendBackupOnPackageResult(mBackupObserver, packageName,
508                                    BackupManager.ERROR_BACKUP_CANCELLED);
509                    Slog.w(TAG, "Backup cancelled. package=" + packageName +
510                            ", cancelAll=" + mCancelAll);
511                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_CANCELLED, packageName);
512                    backupManagerService.tearDownAgentAndKill(currentPackage.applicationInfo);
513                    // Do nothing, clean up, and continue looping.
514                } else if (backupPackageStatus != BackupTransport.TRANSPORT_OK) {
515                    BackupObserverUtils
516                            .sendBackupOnPackageResult(mBackupObserver, packageName,
517                                    BackupManager.ERROR_TRANSPORT_ABORTED);
518                    Slog.w(TAG, "Transport failed; aborting backup: " + backupPackageStatus);
519                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_TRANSPORT_FAILURE);
520                    // Abort entire backup pass.
521                    backupRunStatus = BackupManager.ERROR_TRANSPORT_ABORTED;
522                    return;
523                } else {
524                    // Success!
525                    BackupObserverUtils
526                            .sendBackupOnPackageResult(mBackupObserver, packageName,
527                                    BackupManager.SUCCESS);
528                    EventLog.writeEvent(EventLogTags.FULL_BACKUP_SUCCESS, packageName);
529                    backupManagerService.logBackupComplete(packageName);
530                }
531                cleanUpPipes(transportPipes);
532                cleanUpPipes(enginePipes);
533                if (currentPackage.applicationInfo != null) {
534                    Slog.i(TAG, "Unbinding agent in " + packageName);
535                    backupManagerService.addBackupTrace("unbinding " + packageName);
536                    try {
537                        backupManagerService.getActivityManager().unbindBackupAgent(
538                                currentPackage.applicationInfo);
539                    } catch (RemoteException e) { /* can't happen; activity manager is local */ }
540                }
541            }
542        } catch (Exception e) {
543            backupRunStatus = BackupManager.ERROR_TRANSPORT_ABORTED;
544            Slog.w(TAG, "Exception trying full transport backup", e);
545            mMonitor = BackupManagerMonitorUtils.monitorEvent(mMonitor,
546                    BackupManagerMonitor.LOG_EVENT_ID_EXCEPTION_FULL_BACKUP,
547                    mCurrentPackage,
548                    BackupManagerMonitor.LOG_EVENT_CATEGORY_BACKUP_MANAGER_POLICY,
549                    BackupManagerMonitorUtils.putMonitoringExtra(null,
550                            BackupManagerMonitor.EXTRA_LOG_EXCEPTION_FULL_BACKUP,
551                            Log.getStackTraceString(e)));
552
553        } finally {
554
555            if (mCancelAll) {
556                backupRunStatus = BackupManager.ERROR_BACKUP_CANCELLED;
557            }
558
559            if (RefactoredBackupManagerService.DEBUG) {
560                Slog.i(TAG, "Full backup completed with status: " + backupRunStatus);
561            }
562            BackupObserverUtils.sendBackupFinished(mBackupObserver, backupRunStatus);
563
564            cleanUpPipes(transportPipes);
565            cleanUpPipes(enginePipes);
566
567            unregisterTask();
568
569            if (mJob != null) {
570                mJob.finishBackupPass();
571            }
572
573            synchronized (backupManagerService.getQueueLock()) {
574                backupManagerService.setRunningFullBackupTask(null);
575            }
576
577            mLatch.countDown();
578
579            // Now that we're actually done with schedule-driven work, reschedule
580            // the next pass based on the new queue state.
581            if (mUpdateSchedule) {
582                backupManagerService.scheduleNextFullBackupJob(backoff);
583            }
584
585            Slog.i(RefactoredBackupManagerService.TAG, "Full data backup pass finished.");
586            backupManagerService.getWakelock().release();
587        }
588    }
589
590    void cleanUpPipes(ParcelFileDescriptor[] pipes) {
591        if (pipes != null) {
592            if (pipes[0] != null) {
593                ParcelFileDescriptor fd = pipes[0];
594                pipes[0] = null;
595                try {
596                    fd.close();
597                } catch (IOException e) {
598                    Slog.w(TAG, "Unable to close pipe!");
599                }
600            }
601            if (pipes[1] != null) {
602                ParcelFileDescriptor fd = pipes[1];
603                pipes[1] = null;
604                try {
605                    fd.close();
606                } catch (IOException e) {
607                    Slog.w(TAG, "Unable to close pipe!");
608                }
609            }
610        }
611    }
612
613    // Run the backup and pipe it back to the given socket -- expects to run on
614    // a standalone thread.  The  runner owns this half of the pipe, and closes
615    // it to indicate EOD to the other end.
616    class SinglePackageBackupPreflight implements BackupRestoreTask, FullBackupPreflight {
617        final AtomicLong mResult = new AtomicLong(BackupTransport.AGENT_ERROR);
618        final CountDownLatch mLatch = new CountDownLatch(1);
619        final IBackupTransport mTransport;
620        final long mQuota;
621        private final int mCurrentOpToken;
622
623        SinglePackageBackupPreflight(IBackupTransport transport, long quota, int currentOpToken) {
624            mTransport = transport;
625            mQuota = quota;
626            mCurrentOpToken = currentOpToken;
627        }
628
629        @Override
630        public int preflightFullBackup(PackageInfo pkg, IBackupAgent agent) {
631            int result;
632            try {
633                backupManagerService
634                        .prepareOperationTimeout(mCurrentOpToken,
635                                RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
636                                this, RefactoredBackupManagerService.OP_TYPE_BACKUP_WAIT);
637                backupManagerService.addBackupTrace("preflighting");
638                if (RefactoredBackupManagerService.MORE_DEBUG) {
639                    Slog.d(TAG, "Preflighting full payload of " + pkg.packageName);
640                }
641                agent.doMeasureFullBackup(mQuota, mCurrentOpToken,
642                        backupManagerService.getBackupManagerBinder());
643
644                // Now wait to get our result back.  If this backstop timeout is reached without
645                // the latch being thrown, flow will continue as though a result or "normal"
646                // timeout had been produced.  In case of a real backstop timeout, mResult
647                // will still contain the value it was constructed with, AGENT_ERROR, which
648                // intentionaly falls into the "just report failure" code.
649                mLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
650                        TimeUnit.MILLISECONDS);
651
652                long totalSize = mResult.get();
653                // If preflight timed out, mResult will contain error code as int.
654                if (totalSize < 0) {
655                    return (int) totalSize;
656                }
657                if (RefactoredBackupManagerService.MORE_DEBUG) {
658                    Slog.v(TAG, "Got preflight response; size=" + totalSize);
659                }
660
661                result = mTransport.checkFullBackupSize(totalSize);
662                if (result == BackupTransport.TRANSPORT_QUOTA_EXCEEDED) {
663                    if (RefactoredBackupManagerService.MORE_DEBUG) {
664                        Slog.d(TAG, "Package hit quota limit on preflight " +
665                                pkg.packageName + ": " + totalSize + " of " + mQuota);
666                    }
667                    agent.doQuotaExceeded(totalSize, mQuota);
668                }
669            } catch (Exception e) {
670                Slog.w(TAG, "Exception preflighting " + pkg.packageName + ": " + e.getMessage());
671                result = BackupTransport.AGENT_ERROR;
672            }
673            return result;
674        }
675
676        @Override
677        public void execute() {
678            // Unused.
679        }
680
681        @Override
682        public void operationComplete(long result) {
683            // got the callback, and our preflightFullBackup() method is waiting for the result
684            if (RefactoredBackupManagerService.MORE_DEBUG) {
685                Slog.i(TAG, "Preflight op complete, result=" + result);
686            }
687            mResult.set(result);
688            mLatch.countDown();
689            backupManagerService.removeOperation(mCurrentOpToken);
690        }
691
692        @Override
693        public void handleCancel(boolean cancelAll) {
694            if (RefactoredBackupManagerService.MORE_DEBUG) {
695                Slog.i(TAG, "Preflight cancelled; failing");
696            }
697            mResult.set(BackupTransport.AGENT_ERROR);
698            mLatch.countDown();
699            backupManagerService.removeOperation(mCurrentOpToken);
700        }
701
702        @Override
703        public long getExpectedSizeOrErrorCode() {
704            try {
705                mLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
706                        TimeUnit.MILLISECONDS);
707                return mResult.get();
708            } catch (InterruptedException e) {
709                return BackupTransport.NO_MORE_DATA;
710            }
711        }
712    }
713
714    class SinglePackageBackupRunner implements Runnable, BackupRestoreTask {
715        final ParcelFileDescriptor mOutput;
716        final PackageInfo mTarget;
717        final SinglePackageBackupPreflight mPreflight;
718        final CountDownLatch mPreflightLatch;
719        final CountDownLatch mBackupLatch;
720        private final int mCurrentOpToken;
721        private final int mEphemeralToken;
722        private FullBackupEngine mEngine;
723        private volatile int mPreflightResult;
724        private volatile int mBackupResult;
725        private final long mQuota;
726        private volatile boolean mIsCancelled;
727
728        SinglePackageBackupRunner(ParcelFileDescriptor output, PackageInfo target,
729                IBackupTransport transport, long quota, int currentOpToken) throws IOException {
730            mOutput = ParcelFileDescriptor.dup(output.getFileDescriptor());
731            mTarget = target;
732            mCurrentOpToken = currentOpToken;
733            mEphemeralToken = backupManagerService.generateRandomIntegerToken();
734            mPreflight = new SinglePackageBackupPreflight(transport, quota, mEphemeralToken);
735            mPreflightLatch = new CountDownLatch(1);
736            mBackupLatch = new CountDownLatch(1);
737            mPreflightResult = BackupTransport.AGENT_ERROR;
738            mBackupResult = BackupTransport.AGENT_ERROR;
739            mQuota = quota;
740            registerTask();
741        }
742
743        void registerTask() {
744            synchronized (backupManagerService.getCurrentOpLock()) {
745                backupManagerService.getCurrentOperations().put(mCurrentOpToken, new Operation(
746                        RefactoredBackupManagerService.OP_PENDING, this,
747                        RefactoredBackupManagerService.OP_TYPE_BACKUP_WAIT));
748            }
749        }
750
751        void unregisterTask() {
752            synchronized (backupManagerService.getCurrentOpLock()) {
753                backupManagerService.getCurrentOperations().remove(mCurrentOpToken);
754            }
755        }
756
757        @Override
758        public void run() {
759            FileOutputStream out = new FileOutputStream(mOutput.getFileDescriptor());
760            mEngine = new FullBackupEngine(backupManagerService, out, mPreflight, mTarget, false,
761                    this, mQuota, mCurrentOpToken);
762            try {
763                try {
764                    if (!mIsCancelled) {
765                        mPreflightResult = mEngine.preflightCheck();
766                    }
767                } finally {
768                    mPreflightLatch.countDown();
769                }
770                // If there is no error on preflight, continue backup.
771                if (mPreflightResult == BackupTransport.TRANSPORT_OK) {
772                    if (!mIsCancelled) {
773                        mBackupResult = mEngine.backupOnePackage();
774                    }
775                }
776            } catch (Exception e) {
777                Slog.e(TAG, "Exception during full package backup of " + mTarget.packageName);
778            } finally {
779                unregisterTask();
780                mBackupLatch.countDown();
781                try {
782                    mOutput.close();
783                } catch (IOException e) {
784                    Slog.w(TAG, "Error closing transport pipe in runner");
785                }
786            }
787        }
788
789        public void sendQuotaExceeded(final long backupDataBytes, final long quotaBytes) {
790            mEngine.sendQuotaExceeded(backupDataBytes, quotaBytes);
791        }
792
793        // If preflight succeeded, returns positive number - preflight size,
794        // otherwise return negative error code.
795        long getPreflightResultBlocking() {
796            try {
797                mPreflightLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
798                        TimeUnit.MILLISECONDS);
799                if (mIsCancelled) {
800                    return BackupManager.ERROR_BACKUP_CANCELLED;
801                }
802                if (mPreflightResult == BackupTransport.TRANSPORT_OK) {
803                    return mPreflight.getExpectedSizeOrErrorCode();
804                } else {
805                    return mPreflightResult;
806                }
807            } catch (InterruptedException e) {
808                return BackupTransport.AGENT_ERROR;
809            }
810        }
811
812        int getBackupResultBlocking() {
813            try {
814                mBackupLatch.await(RefactoredBackupManagerService.TIMEOUT_FULL_BACKUP_INTERVAL,
815                        TimeUnit.MILLISECONDS);
816                if (mIsCancelled) {
817                    return BackupManager.ERROR_BACKUP_CANCELLED;
818                }
819                return mBackupResult;
820            } catch (InterruptedException e) {
821                return BackupTransport.AGENT_ERROR;
822            }
823        }
824
825
826        // BackupRestoreTask interface: specifically, timeout detection
827
828        @Override
829        public void execute() { /* intentionally empty */ }
830
831        @Override
832        public void operationComplete(long result) { /* intentionally empty */ }
833
834        @Override
835        public void handleCancel(boolean cancelAll) {
836            if (RefactoredBackupManagerService.DEBUG) {
837                Slog.w(TAG, "Full backup cancel of " + mTarget.packageName);
838            }
839
840            mMonitor = BackupManagerMonitorUtils.monitorEvent(mMonitor,
841                    BackupManagerMonitor.LOG_EVENT_ID_FULL_BACKUP_CANCEL,
842                    mCurrentPackage, BackupManagerMonitor.LOG_EVENT_CATEGORY_AGENT, null);
843            mIsCancelled = true;
844            // Cancel tasks spun off by this task.
845            backupManagerService.handleCancel(mEphemeralToken, cancelAll);
846            backupManagerService.tearDownAgentAndKill(mTarget.applicationInfo);
847            // Free up everyone waiting on this task and its children.
848            mPreflightLatch.countDown();
849            mBackupLatch.countDown();
850            // We are done with this operation.
851            backupManagerService.removeOperation(mCurrentOpToken);
852        }
853    }
854}
855