onRestore not invoked for my custom BackupAgent

In my experience, for some odd reason (which I have yet to identify), logging statements made in BackupAgents don't show up in the logs. Nonetheless, I have been able to confirm that the onRestore method is in fact properly run.

In your question you indicate that the onRestore method "does not seem to be called" because you are unable to see the proper logs. Can you instead confirm that the result is failing (i.e. that data that should be properly restored isn't)?

I had this problem and the root cause was that I had a bug in my onBackup preventing it from completing, so onBackup was called but onRestore was not. Fixing the exception in onBackup caused onRestore to be called.

Also Log messages in onBackup and onRestore do show up in the logs. If you set a log filter on the tag "backup" and use something with backup in it for your log tag. You will see logging from the system and yours. Here is what I get

09-08 17:06:56.581      294-352/system_process V/BackupServiceBinder﹕ doBackup() invoked09-08 17:06:56.591      294-352/system_process D/PerformBackupTask﹕ starting agent for backup of BackupRequest{pkg=android}09-08 17:06:56.591      294-352/system_process D/BackupManagerService﹕ awaiting agent for ApplicationInfo{40d5efc0 android}09-08 17:06:56.591      294-308/system_process D/BackupManagerService﹕ agentConnected pkg=android agent=android.app.backup.BackupAgent$BackupServiceBinder@4112a22809-08 17:06:56.601      294-352/system_process V/BackupServiceBinder﹕ doBackup() invoked09-08 17:06:56.601      294-352/system_process D/BackupHelperDispatcher﹕ handling existing helper 'wallpaper' android.app.backup.WallpaperBackupHelper@4114915009-08 17:06:56.621      294-352/system_process D/PerformBackupTask﹕ starting agent for backup of BackupRequest{pkg=com.catglo.sellpr}09-08 17:06:56.661      294-352/system_process D/BackupManagerService﹕ awaiting agent for ApplicationInfo{41074748 com.catglo.sellpr}09-08 17:06:56.781      294-514/system_process D/BackupManagerService﹕ agentConnected pkg=com.catglo.sellpr agent=android.os.BinderProxy@410768c809-08 17:06:56.791    2263-2274/com.catglo.sellpr V/BackupServiceBinder﹕ doBackup() invoked09-08 17:06:56.791    2263-2274/com.catglo.sellpr I/backup﹕ onBackup called09-08 17:06:57.251      294-352/system_process I/PerformBackupTask﹕ Backup pass finished.

in the above log com.catglo.sellpr is from my app and the line that reads com.catglo.sellpr I/backup﹕ onBackup called is the log message in my code. For the onRestore I get

09-08 17:13:34.431      294-352/system_process D/BackupManagerService﹕ MSG_RUN_RESTORE observer=android.app.backup.IRestoreObserver$Stub$Proxy@413132c009-08 17:13:34.511      294-352/system_process V/BackupServiceBinder﹕ doRestore() invoked09-08 17:13:34.561      294-352/system_process D/BackupManagerService﹕ awaiting agent for ApplicationInfo{41074748 com.catglo.sellpr}09-08 17:13:34.561      294-427/system_process D/BackupManagerService﹕ agentConnected pkg=com.catglo.sellpr agent=android.os.BinderProxy@41127ee009-08 17:13:34.571    2263-2276/com.catglo.sellpr V/BackupServiceBinder﹕ doRestore() invoked09-08 17:13:34.571    2263-2276/com.catglo.sellpr I/backup﹕ onRestore called

Earlier I had an exception in onBackup and my log from onRestore was never called but the system messages related to restore were.

The app will not Force Close because of an exception in the backup.