Tear down agents properly at EOD in full restore

The restore engine wasn't tearing down the bound agent after reaching
the end of data for the app, and furthermore was allowing the restore
operation to resume running the queue before all data had been delivered
to the current target.

Also make LocalTransport deliver data in 2K chunks rather than 32K,
as a first step towards making its timing characteristics more like
we'll see in networked situations.

Finally, added a bunch of MORE_DEBUG output for finding odd bugs
like this.

Change-Id: Icdbe6a070af6cc7c708a938ad044108d40ebce9a

1 files changed, 18 insertions, 1 deletions

diff --git a/services/backup/java/com/android/server/backup/BackupManagerService.java b/services/backup/java/com/android/server/backup/BackupManagerService.java
index ce9e85e..17a5263 100644
--- a/services/backup/java/com/android/server/backup/BackupManagerService.java
+++ b/services/backup/java/com/android/server/backup/BackupManagerService.java
@@ -3539,6 +3539,11 @@ public class BackupManagerService extends IBackupManager.Stub {
                             // In all cases we need to give the transport its finish callback
                             int finishResult = transport.finishBackup();
 
+                            if (MORE_DEBUG) {
+                                Slog.i(TAG, "Done trying to send backup data: result="
+                                        + result + " finishResult=" + finishResult);
+                            }
+
                             // If we were otherwise in a good state, now interpret the final
                             // result based on what finishBackup() returned.  If we're in a
                             // failure case already, preserve that result and ignore whatever
@@ -3561,7 +3566,7 @@ public class BackupManagerService extends IBackupManager.Stub {
                             // do nothing, clean up, and continue looping
                         } else if (result != BackupTransport.TRANSPORT_OK) {
                             if (DEBUG) {
-                                Slog.i(TAG, "Transport failed; aborting backup");
+                                Slog.i(TAG, "Transport failed; aborting backup: " + result);
                                 return;
                             }
                         }
@@ -4083,6 +4088,9 @@ public class BackupManagerService extends IBackupManager.Stub {
                             // okay, if the remote end failed at any point, deal with
                             // it by ignoring the rest of the restore on it
                             if (!agentSuccess) {
+                                if (DEBUG) {
+                                    Slog.i(TAG, "Agent failure; ending restore");
+                                }
                                 mBackupHandler.removeMessages(MSG_TIMEOUT);
                                 tearDownPipes();
                                 tearDownAgent(mTargetApp);
@@ -4124,6 +4132,11 @@ public class BackupManagerService extends IBackupManager.Stub {
 
             // If we got here we're either running smoothly or we've finished
             if (info == null) {
+                if (MORE_DEBUG) {
+                    Slog.i(TAG, "No [more] data for this package; tearing down");
+                }
+                tearDownPipes();
+                tearDownAgent(mTargetApp);
                 setRunning(false);
             }
             return (info != null);
@@ -7064,6 +7077,10 @@ if (MORE_DEBUG) Slog.v(TAG, "   + got " + nRead + "; now wanting " + (size - soF
                     // Don't proceed until the engine has torn down the agent etc
                     eThread.waitForResult();
 
+                    if (MORE_DEBUG) {
+                        Slog.i(TAG, "engine thread finished; proceeding");
+                    }
+
                     // Now we're really done with this one too
                     IoUtils.closeQuietly(mEnginePipes[0]);