Signal-android: Signal Crashes on Backup Import (OOM)

[castanley]

• [X] I have searched open and closed issues for duplicates
• [X] I am submitting a bug report for existing functionality that does not work as intended
• [X] I have read https://github.com/signalapp/Signal-Android/wiki/Submitting-useful-bug-reports
• [X] This isn't a feature request or a discussion topic
  Possibly related to:
  

  https://github.com/signalapp/Signal-Android/issues/9136

Bug description

Restoring a backup that is 11.4GB in size causes Signal to crash (OOM)

Steps to reproduce

Create a backup
Import backup on a separate device

Actual result: Application crashes
Expected result: Messages to appear on new device

Device info

Device: Google Pixel 4
Android version: 10.0
Signal version: 4.49.14

Link to debug log (Not able to get debug log because do not have the option on first import. Below is LogCat

11-02 20:03:25.258 12377 12430 E AndroidRuntime: FATAL EXCEPTION: AsyncTask #1
11-02 20:03:25.258 12377 12430 E AndroidRuntime: Process: org.thoughtcrime.securesms, PID: 12377
11-02 20:03:25.258 12377 12430 E AndroidRuntime: java.lang.RuntimeException: An error occurred while executing doInBackground()
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at android.os.AsyncTask$4.done(AsyncTask.java:399)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:383)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at java.util.concurrent.FutureTask.setException(FutureTask.java:252)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at java.util.concurrent.FutureTask.run(FutureTask.java:271)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:289)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at java.lang.Thread.run(Thread.java:919)
11-02 20:03:25.258 12377 12430 E AndroidRuntime: Caused by: java.lang.OutOfMemoryError: Failed to allocate a 874830208 byte allocation with 4116870 free bytes and 508MB until OOM, target footprint 8233742, growth limit 536870912
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at org.thoughtcrime.securesms.backup.FullBackupImporter$BackupRecordInputStream.readFrame(FullBackupImporter.java:3)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at org.thoughtcrime.securesms.backup.FullBackupImporter$BackupRecordInputStream.readFrame(FullBackupImporter.java:1)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at org.thoughtcrime.securesms.backup.FullBackupImporter.importFile(FullBackupImporter.java:4)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at org.thoughtcrime.securesms.registration.fragments.RestoreBackupFragment$2.doInBackground(RestoreBackupFragment.java:7)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at org.thoughtcrime.securesms.registration.fragments.RestoreBackupFragment$2.doInBackground(RestoreBackupFragment.java:1)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at android.os.AsyncTask$3.call(AsyncTask.java:378)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
11-02 20:03:25.258 12377 12430 E AndroidRuntime:    ... 4 more
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger: 
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger: java.lang.RuntimeException: An error occurred while executing doInBackground()
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at android.os.AsyncTask$4.done(AsyncTask.java:399)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:383)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at java.util.concurrent.FutureTask.setException(FutureTask.java:252)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at java.util.concurrent.FutureTask.run(FutureTask.java:271)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:289)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at java.lang.Thread.run(Thread.java:919)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger: Caused by: java.lang.OutOfMemoryError: Failed to allocate a 874830208 byte allocation with 4116870 free bytes and 508MB until OOM, target footprint 8233742, growth limit 536870912
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at org.thoughtcrime.securesms.backup.FullBackupImporter$BackupRecordInputStream.readFrame(FullBackupImporter.java:3)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at org.thoughtcrime.securesms.backup.FullBackupImporter$BackupRecordInputStream.readFrame(FullBackupImporter.java:1)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at org.thoughtcrime.securesms.backup.FullBackupImporter.importFile(FullBackupImporter.java:4)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at org.thoughtcrime.securesms.registration.fragments.RestoreBackupFragment$2.doInBackground(RestoreBackupFragment.java:7)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at org.thoughtcrime.securesms.registration.fragments.RestoreBackupFragment$2.doInBackground(RestoreBackupFragment.java:1)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at android.os.AsyncTask$3.call(AsyncTask.java:378)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   at java.util.concurrent.FutureTask.run(FutureTask.java:266)
11-02 20:03:25.259 12377 12430 E UncaughtExceptionLogger:   ... 4 more
11-02 20:03:25.270  1316 14159 I DropBoxManagerService: add tag=data_app_crash isTagEnabled=true flags=0x2
11-02 20:03:25.271  1316  2542 W ActivityTaskManager:   Force finishing activity org.thoughtcrime.securesms/.registration.RegistrationNavigationActivity
11-02 20:03:25.295 12377 12430 I Process : Sending signal. PID: 12377 SIG: 9
11-02 20:03:25.295  1316  1350 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver
11-02 20:03:25.295  1316  1350 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver
11-02 20:03:25.321  1316  8698 I WindowManager: WIN DEATH: Window{f7d94ee u0 org.thoughtcrime.securesms/org.thoughtcrime.securesms.registration.RegistrationNavigationActivity}
11-02 20:03:25.321  1316  2096 I ActivityManager: Process org.thoughtcrime.securesms (pid 12377) has died: vis+99 TOP 
11-02 20:03:25.321  1316  1352 I libprocessgroup: Successfully killed process cgroup uid 10228 pid 12377 in 0ms
11-02 20:03:25.322  1316  1735 W InputDispatcher: channel 'f7d94ee org.thoughtcrime.securesms/org.thoughtcrime.securesms.registration.RegistrationNavigationActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0x9
11-02 20:03:25.322  1316  1735 E InputDispatcher: channel 'f7d94ee org.thoughtcrime.securesms/org.thoughtcrime.securesms.registration.RegistrationNavigationActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
11-02 20:03:25.322   793   793 I Zygote  : Process 12377 exited due to signal 9 (Killed)
11-02 20:03:25.323  1316  8698 W InputDispatcher: Attempted to unregister already unregistered input channel 'f7d94ee org.thoughtcrime.securesms/org.thoughtcrime.securesms.registration.RegistrationNavigationActivity (server)'

[johanw666]

Caused by: java.lang.OutOfMemoryError

With a backup file that large I can imagine why. On many devices that will probably give an out of storage space error.

In this case, if you still have access to both devices and have root, you could try this approach: https://community.signalusers.org/t/howto-manual-backup-restore-if-full-backup-does-not-work/2462

[castanley]

I don't have root, but thanks for the input.

To clarify, I have successfully restored backups of this size on previous versions. I agree with the storage comment, however I have a 128gb device. Secondly, an OOM error seems to me like the import function within signal is not cleaning up messages as they are processed. I haven't yet checked the source code so I don't know how it is being done, but it would be silly to try and pull everything from disk into memory.

I deleted most messages and brought the file size down to 5gb and still get the error.

[bepaald]

I should first note I am _not_ a java programmer (but do have quite a bit of knowledge on the backup format).

The backup file consists of a series of frames, each preceded by a 4 byte number indicating the size of the following frame in bytes. The debug log shows the program is trying to allocate over 800MB of memory on this line. Apparently, the four-byte frame header says the next frame is going to be 834MB, and then that amount of memory is allocated to read the next frame into (tried to be allocated anyway, it obviously fails). As far as I know, no frame is ever supposed to be that large. The size of attachments isn't even included in this number, but even if that was the case, this is well over the maximum attachment size.

Anyway. I have no solution, just thought I'd share my thoughts on this problem. That is, it is not a memory cleanup problem (Java does not have any way of cleaning up memory, the VM is supposed to do that automatically). It seems like this four byte header is somehow incorrect in your backup file. I would normally say the file was just corrupted somehow, but you seem to be able to reproduce this, so now I don't know how this could happen.

[alan-signal]

Not able to get debug log because do not have the option on first import. Below is LogCat

You can now actually, tap any title on any registration page 8 times.

[davidjmeier]

I'm running into this on a device replacement workflow. The problem is as described, I have a 10.3GB restore file that I'm not able to transfer to a replacement device. This is problematic because I have to return the replaced device in a timely manner and will lose physical access to the original in the next week. Signal no longer supports an "any time" import - it's at registration or nothing currently. This means the person in this situation only has the choice to start over and lose everything (years of Signal messages, pictures, conversations, etc). Is this at all prioritized or have an ETA or beta build we could test to get this moving? Having a broken migration process seems to be a huge blocker. Thank you!

[greyson-signal]

To say it's "broken" is perhaps oversimplifying it. Backups largely work, and I've been through many backup-restore flows on various occasions with an 8+ GB backup file. But there are cases where either the backup file itself, or the reading of the backup file, gets into a bad state.

I once experienced a bad backup restore (with an identical OOM stack trace) that was a result of a bad file copy. Simply copying the same file over a second time fixed things. I would try that first.

However, there are situations where re-copying doesn't work, and we have to figure out if that's because of an error during writing or during reading. These are tricky to debug because we can't recreate the issue, and for obvious reasons we can't ask for the backup files of affected users.

I may be able to create a build that has extremely verbose logging, but I'd have to take some time to figure out what that logging would be.

[davidjmeier]

Thanks @greyson-signal. I tried twice last night - but let me move the file off the original device in a different way. Thanks for the response! If I can't get it to go I'll hop back and see if we can work out the detailed debug build. Much appreciated.

[davidjmeier]

@greyson-signal I validated the hash of the backup on the source phone and also on the destination phone. Both match, Signal crashes as it approaches the end of the restore. Is there any way to get an extended debug build or grab the debug from the initial onboarding as it stands?

Thanks!

[m-terlinde]

Hey guys, i have the same problem with the current version and a backup of round about 550 MB.

Please find my logs at debuglogs.com

If I can provide more information, feel free to ask!

[bepaald]

@greyson-signal
Could this have something to do with the change to avatars to use recipientId instead of 'name'?

I notice in the exporter that the avatar write function (https://github.com/signalapp/Signal-Android/blob/master/src/org/thoughtcrime/securesms/backup/FullBackupExporter.java#L326) sets .setRecipientId(avatarName) (which used to be setName() before the change), but the 'avatarName' that is used in that call is (unchanged since before the migration): outputStream.write(avatar.getName(), new FileInputStream(avatar), avatar.length()); (https://github.com/signalapp/Signal-Android/blob/master/src/org/thoughtcrime/securesms/backup/FullBackupExporter.java#L101). So it seems to me, the old name (eg _"[phone]"_) is used as the recipientid. The backup importer does check if the avatar in the backup 'hasRecipientId()', but I assume this evaluates to true simply because 'setRecipientId()' was used to set the old name.

Anyway, I haven't tested this extensively, but that's just my guess from reading the code. Also, from personal experience I know the Avatar frames are (almost) the last frames written to the backup file which would explain why nearly everyone (here and in the closed duplicates) encounter this issue when the restoration is nearly complete. Lastly, the recipientid migration is just simply the only change to the backup exporter between now and before the troubles started.

[stonerl]

I do have the same problem with a 600 MB backup. I created a backup with the latest release, 4.49.18, and tried to restore it with the very same version. Here the crash also happens right at the end of the restore.

[greyson-signal]

@bepaald I very much appreciate the research, but the code you're referencing is being misinterpreted.

https://github.com/signalapp/Signal-Android/blob/master/src/org/thoughtcrime/securesms/backup/FullBackupExporter.java#L101
The avatar.getName() here references the filename, which while it used to be a phone number, is now a recipientId. That happens in AvatarMigrationJob.java, which is migration that was put in place around the same time the backup exporter was changed.

Lastly, the recipientid migration is just simply the only change to the backup exporter between now and before the troubles started

If we're being honest, this issue has cropped up from time to time for quite a while. I am trying to determine if this represents an uptick in occurrences, and it's hard to say. Regardless, I am trying to at least get more debugging in place.

[bepaald]

Yes, I was _just_ about to post to say to disregard my previous comment. I had come to the same conclusion.

I have been following the backup restoration bugs quite closely for the last while, and helped quite a few people (mostly in #8355, but also on the community forums and through other channels) fix their broken backups. I do feel that there is a bit of an increase in the bug reports lately, especially the wrong frame size. In fact, I have seen the wrong frame size only once before (and my program was able to fix that backup as well), but maybe it is just becoming a more prominent manifestation of the same problem now that the import ignores the bad MAC (which precedes it in multiple of these reports).

Anyway, I apologize for the noise, maybe one of my backups will finally go bad one of these days, then hopefully I'll be able to help a bit better :)

[davidjmeier]

@greyson-signal I hate to ask, but I am under a time constraint and have to send back an RMA phone. The user I'm transferring the old Signal database cannot switch to a new phone without the old messages. I'm curious if there's any indication of what the bug is and if there's any way for me to help test? Otherwise I will have the person send back the new phone until this issue is resolved. Thank you!

Edit: I just started looking at @bepaald tooling and will give that a shot to see if I can fix the backup. Is there any reason I should have the end user move to Signal beta that would potentially help get this reimported?

[m-terlinde]

I created a new backup on the old phone using a new key.
It produced the same result.

https://debuglogs.org/7ef5ad3dfb5abda321a1f361556619d43c3eb029bda058ba48fe81706944c186

So this seems somehow reproducible.

[g2bb]

@greyson-signal I hate to ask, but I am under a time constraint and have to send back an RMA phone. The user I'm transferring the old Signal database cannot switch to a new phone without the old messages. I'm curious if there's any indication of what the bug is and if there's any way for me to help test? Otherwise I will have the person send back the new phone until this issue is resolved. Thank you!

Edit: I just started looking at @bepaald tooling and will give that a shot to see if I can fix the backup. Is there any reason I should have the end user move to Signal beta that would potentially help get this reimported?

You can copy the old file over to your new phone. Navigate to /Internal Storage/Signal/Backups or /sdcard/Signal/Backups on your old phone. Then just make sure you have a copy of the key and you should be fine, you'll have to use the default SMS on the new device temporarily, but once they fix the bug you should be able to restore

[aaronjanse]

You can copy the old file over to your new phone. Navigate to /Internal Storage/Signal/Backups or /sdcard/Signal/Backups on your old phone. Then just make sure you have a copy of the key and you should be fine, you'll have to use the default SMS on the new device temporarily, but once they fix the bug you should be able to restore

That's assuming the problem is with backup file reading, not the way that backup files are created.

[g2bb]

You can copy the old file over to your new phone. Navigate to /Internal Storage/Signal/Backups or /sdcard/Signal/Backups on your old phone. Then just make sure you have a copy of the key and you should be fine, you'll have to use the default SMS on the new device temporarily, but once they fix the bug you should be able to restore
That's assuming the problem is with backup file reading, not the way that backup files are created.

True, but I don't even want to think of that as a possibility >.<

[spencerterry]

I am seeing the same issue with a 256mb backup file. Crashes at end of restore

Debug log submitted

https://debuglogs.org/641ea4ebda03a6f6e54ad37ccb1c311494cf63fdcf4f80d888efc3642f06749c

[bepaald]

@davidjmeier I'd be very curious to hear the results. Please realize that it's hard to deal with all different possible unexpected bytes in an invalid backup file. It is very possible that the program does not fix this particular problem (yet!). Also, since I've never had a bad backup file myself (apart from a few handcrafted ones), supporting new types of broken backups depends on a back-and-forth of reporting results and running new custom builds of the program to get more information. This could be quite a long process.

Having said that, I am fairly confident I can fix nearly any broken backups. I've done the normal ones, with just 1 bad MAC, but also one where the bad MAC was followed by a bad framesize (which is what's happening to most people in this bug report). If all else fails, I've even generated a working backup for an user who had accidentally truncated the last gigabyte off the end of his backup file. So that should be a bit of an assurance that the program can restore at least anything before the corruption (which seems to be close to the end of the file for most people here).

Anyway, just wanted to say good luck and feel free to tell me the results or ask for help.

[davidjmeier]

@davidjmeier I'd be very curious to hear the results..

Thanks @bepaald!

So, I ran your tool and got this output:

Got frame, breaking
FRAME 129248 (022.6%)... Failed to get valid frame from decoded data...
Data: (hex:) 70 20 85 04 00 00 00 00 10 20 48 01 00 00 00 00 e0
Attachment data with BAD MAC was encountered:
Short info on message to which attachment with bad mac belongs (1/1):
Date          : 2019-11-01 01:25:38 +0000 (1572571538000)
Date received : 2019-11-01 01:25:52 +0000 (1572571552000)
Sent by       : 
Message body  :

---------------------------

Exporting backup to 'signal-2019-11-17-fixed.backup'
Writing HeaderFrame...
Writing DatabaseVersionFrame...
Writing SqlStatementFrame(s)...
  Dealing with table 'sms'... 113241/113241 entries...done
  Dealing with table 'mms'... 7103/7103 entries...done
  Dealing with table 'part'... 347/4005 entries...Warning: attachment data not found (rowid: 348, uniqueid: 1515550726442)
  Dealing with table 'part'... 394/4005 entries...Warning: attachment data not found (rowid: 395, uniqueid: 1515717336259)
  Dealing with table 'part'... 395/4005 entries...Warning: attachment data not found (rowid: 396, uniqueid: 1515717343952)
  Dealing with table 'part'... 410/4005 entries...Warning: attachment data not found (rowid: 411, uniqueid: 1515817853253)
  Dealing with table 'part'... 412/4005 entries...Warning: attachment data not found (rowid: 413, uniqueid: 1515817855026)
  Dealing with table 'part'... 415/4005 entries...Warning: attachment data not found (rowid: 416, uniqueid: 1515817857461)
  Dealing with table 'part'... 1011/4005 entries...Warning: attachment data not found (rowid: 1012, uniqueid: 1530409334257)
  Dealing with table 'part'... 1128/4005 entries...Warning: attachment data not found (rowid: 1129, uniqueid: 1532272034729)
  Dealing with table 'part'... 1129/4005 entries...Warning: attachment data not found (rowid: 1130, uniqueid: 1532272135185)
  Dealing with table 'part'... 1130/4005 entries...Warning: attachment data not found (rowid: 1131, uniqueid: 1532272296845)
  Dealing with table 'part'... 1131/4005 entries...Warning: attachment data not found (rowid: 1132, uniqueid: 1532272488137)
  Dealing with table 'part'... 3253/4005 entries...Warning: attachment data not found (rowid: 3254, uniqueid: 1564280211748)
  Dealing with table 'part'... 4005/4005 entries...done
  Dealing with table 'thread'... 0/0 entries...
  Dealing with table 'identities'... 0/0 entries...
  Dealing with table 'drafts'... 0/0 entries...
  Dealing with table 'push'... 0/0 entries...
  Dealing with table 'groups'... 0/0 entries...
  Dealing with table 'group_receipts'... 0/0 entries...
  Dealing with table 'job_spec'... 0/0 entries...
  Dealing with table 'constraint_spec'... 0/0 entries...
  Dealing with table 'dependency_spec'... 0/0 entries...
  Dealing with table 'sticker'... 0/0 entries...
  Dealing with table 'recipient'... 0/0 entries...
Writing SharedPrefFrame(s)...
Writing Avatars...
Writing Stickers...
Writing EndFrame...
Error: EndFrame not found

I tried taking the newly created backup by your tool, and everything seemed to be working well (no crash), but at the end of the import I get "Bad Password". Any thoughts? There's clearly a corrupt message, I'm wondering if I just take that message out from 11-01 if that will help.

Edit: I manually removed the message that signalbackup-tools (@bepaald) found as corrupt and the backup now restores correctly.

[greyson-signal]

Ok, so I feel pretty sure I figured out what caused the uptick in this error. We did some work on attachment de-duping last release, and there was a period of time where a bug was live in production that could cause attachment corruption. If you were affected by this, when we created a backup, we would write the wrong attachment size to the frame header in the backup. On import, we then read the wrong amount of data, interpret an incorrect block as a new frame size, and then likely throw an OOM or a negative size exception.

So, good news is that we're releasing a fix on the export side in 4.50.4, which is releasing soon. It also includes additional size checks to make sure this type of bug can't happen again.

However, the bad news is that there's really no automated way to fix these affected backup files. The way the backup format is written, if you give it the wrong size for the next frame, the whole thing just kind of falls apart. And given the way tables and stuff are written, it's unclear what data could be written after this bad attachment, so it's not safe to just stop reading the backup file right there or something.

I'm sorry, and if I think of some way to bulk-fix these backups or something, I'll update this space.

[g2bb]

@greyson-signal so just to be clear, you've implemented to fix for backups going forward, but all of us here who currently have broken backups will not be able to restore them?

[bepaald]

@davidjmeier Thanks for reporting back! Though my program didn't exactly fix your backup (or even behave as I expected, oops), I'm very happy it helped you create a working backup!

For everybody not able to recreate a new backup (@g2bb), I will push some changes to my program that might already fix this problem (though please don't get your hopes up, it's all theory at this point). To try it out call the program as such:
signalbackup-tools --assumebadframesizeonbadmac --output [fixed.backup] --opassword [newpassword] [broken.backup] [passwordforbroken]

Even if it doesn't work, I'm fairly certain I can fix these backups with a little patience (and possibly some extra information). Please feel free to ask for more help or report results. Either here (if it's ok with the signal team), or on my github (https://github.com/bepaald/signalbackup-tools, the existing open issue is already a sort of general-help forum anyway).

@greyson-signal Are there any details you can give on the wrong size written? Is it, for example, always too short or always too long? Also, when you say the wrong attachment size is written to the _frame header_, do you mean the size of the actual attachment data, which is only written _into_ the (encrypted) preceding AttachmentFrame protobuf struct, or do you mean the unencrypted 4 byte frame size that precedes the AttachmentFrame (but does not include the size of the actual attachment data)? I'm assuming the former, but I just want to be sure. Thanks!

[stonerl]

Is there a way to sync the old messages from the Desktop Client towards the Smartphone app? Although I also cannot restore my Backup, all messages reside on my Desktop and new messages get appended to the existing conversations.

Basically the history and all files are there. Just not on my phone.

[greyson-signal]

@g2bb I'm sorry but yes, as of now, that is the case.

@bepaald

always too short or always too long

No guarantees, but it is likely that the size is almost always longer than it should be.

do you mean the size of the actual attachment data, which is only written into the (encrypted) preceding AttachmentFrame protobuf struct

This one. Specifically, what was written here was the problem:
https://github.com/signalapp/Signal-Android/blob/master/src/org/thoughtcrime/securesms/backup/FullBackupExporter.java#L360

@stonerl No, we don't do message syncing of old messages across linked devices.

[bepaald]

@greyson-signal Thanks!

[bepaald]

@greyson-signal One last question if you don't mind. Is the wrong data size the only bad data written? I mean, is the attachment data that follows the AttachmentFrame otherwise correct (complete, properly encrypted and with a correct MAC)?

I've already created a backup file that has a wrong attachment data size in one of the frames, and my program is able to fix this backup both by dropping the attachment, as well as by actually correcting the wrong size info. But, of course, if the attachment data is still corrupt in some other way, or the MAC is calculated over the wrong data, it wouldn't work anyway.

*Disclaimer: even though I tested it somewhat, this is still highly experimental.

[~/programming/signalbackup-tools] $ ll original.backup broken.backup 
-rw-r--r-- 1 bepaald bepaald 99272480 nov 18 20:20 broken.backup
-rw-r--r-- 1 bepaald bepaald 99272480 nov 18 21:20 original.backup
[~/programming/signalbackup-tools] $ ./signalbackup-tools broken.backup 046264412777597056723900018790 --assumebadframesizeonbadmacsignalbackup-tools source version 20191118.184645
IV: (hex:) 97 24 cd da a2 76 e9 f5 91 5d 29 8b f8 b2 19 e3 (size: 16)
SALT: (hex:) 68 75 80 2b d3 ed aa 33 68 6d 2d 38 fd a7 cc e3 44 20 1b aa 02 70 88 50 44 70 ed d9 7b 33 26 d9 (size: 32)
BACKUPKEY: (hex:) 60 ee 9d ca df ef f2 7f 27 94 99 c1 2b f0 d1 ca 24 f7 08 1f 6a e6 b9 64 b7 d0 67 6a d5 d2 84 89 (size: 32)
CIPHERKEY: (hex:) 4c 52 c0 08 ae 98 a9 5c 2a 3a a1 df 60 98 6d eb 1e bb 4b 5a 5e b5 57 7c b8 3e 76 97 e6 b2 df ec (size: 32)
MACKEY: (hex:) 57 66 55 c6 f6 87 87 a0 59 22 aa 12 ae ee 72 28 6a f7 d1 19 ad ea ca 31 44 48 45 f5 68 97 d6 18 (size: 32)
COUNTER: 2535771610
Reading backup file...
FRAME 175 (001.1%)... 
WARNING: Bad MAC in attachmentdata: theirMac: (hex:) 4a 0b 23 a8 07 fc 32 3d 4d d5
                                      ourMac: (hex:) aa 61 85 96 88 0f 30 8c 3b 7f 07 8e e1 e1 ad 7d 22 d9 8e 2b a6 53 eb 8d 50 95 6f 11 45 d3 bb bd
Starting bruteforcing offset to next valid frame... starting after: 1057302
Checking offset 75780 bytes
GOT GOOD MAC AT OFFSET 75784 BYTES!
Now let's try and find out how many frames we skipped to get here....
Checking if we skipped 0 frames... YEAH!
Good frame: 177
CORRECT FRAME_NUMBER:SIZE = 176:75745

Got frame, breaking
FRAME 379 (100.0%)... Read entire backup file...

done!
[~/programming/signalbackup-tools] $ ./signalbackup-tools broken.backup 046264412777597056723900018790 --editattachmentsize 176,75745 --output fixed.backup --opassword 046264412777597056723900018790
signalbackup-tools source version 20191118.184645
IV: (hex:) 97 24 cd da a2 76 e9 f5 91 5d 29 8b f8 b2 19 e3 (size: 16)
SALT: (hex:) 68 75 80 2b d3 ed aa 33 68 6d 2d 38 fd a7 cc e3 44 20 1b aa 02 70 88 50 44 70 ed d9 7b 33 26 d9 (size: 32)
BACKUPKEY: (hex:) 60 ee 9d ca df ef f2 7f 27 94 99 c1 2b f0 d1 ca 24 f7 08 1f 6a e6 b9 64 b7 d0 67 6a d5 d2 84 89 (size: 32)
CIPHERKEY: (hex:) 4c 52 c0 08 ae 98 a9 5c 2a 3a a1 df 60 98 6d eb 1e bb 4b 5a 5e b5 57 7c b8 3e 76 97 e6 b2 df ec (size: 32)
MACKEY: (hex:) 57 66 55 c6 f6 87 87 a0 59 22 aa 12 ae ee 72 28 6a f7 d1 19 ad ea ca 31 44 48 45 f5 68 97 d6 18 (size: 32)
COUNTER: 2535771610
Reading backup file...
FRAME 175 (001.1%)... Editing attachment data size in AttachmentFrame
Frame number: 176
        Type: ATTACHMENT
         - row id          : 7 (8 bytes)
         - attachment id   : 1529478704770 (8 bytes)
         - length          : 77545 (8 bytes)
Frame number: 176
        Type: ATTACHMENT
         - row id          : 7 (8 bytes)
         - attachment id   : 1529478704770 (8 bytes)
         - length          : 75745 (4 bytes)
FRAME 379 (100.0%)... Read entire backup file...

done!

Exporting backup to 'fixed.backup'
Writing HeaderFrame...
Writing DatabaseVersionFrame...
Writing SqlStatementFrame(s)...
  Dealing with table 'sms'... 51/51 entries...done
  Dealing with table 'mms'... 60/60 entries...done
  Dealing with table 'part'... 18/96 entries...Warning: attachment data not found (rowid: 20, uniqueid: 1543396991046)
  Dealing with table 'part'... 25/96 entries...Warning: attachment data not found (rowid: 27, uniqueid: 1544256079658)
  Dealing with table 'part'... 92/96 entries...Warning: attachment data not found (rowid: 95, uniqueid: 1554296247843)
  Dealing with table 'part'... 93/96 entries...Warning: attachment data not found (rowid: 96, uniqueid: 1554296249229)
  Dealing with table 'part'... 96/96 entries...done
  Dealing with table 'thread'... 2/2 entries...done
  Dealing with table 'identities'... 3/3 entries...done
  Dealing with table 'drafts'... 0/0 entries...
  Dealing with table 'push'... 0/0 entries...
  Dealing with table 'groups'... 1/1 entries...done
  Dealing with table 'group_receipts'... 5/5 entries...done
  Dealing with table 'job_spec'... 1/1 entries...done
  Dealing with table 'constraint_spec'... 0/0 entries...
  Dealing with table 'dependency_spec'... 0/0 entries...
  Dealing with table 'sticker'... 0/0 entries...
  Dealing with table 'recipient'... 13/13 entries...done
Writing SharedPrefFrame(s)...
Writing Avatars...
Writing Stickers...
Writing EndFrame...
Done!
[~/programming/signalbackup-tools] $ md5sum original.backup broken.backup fixed.backup 
a422e4050cfe57bf50431ad3cc9ecc05  original.backup
4516386a42a31c34ca0c8a9f5b237036  broken.backup
a422e4050cfe57bf50431ad3cc9ecc05  fixed.backup
[~/programming/signalbackup-tools] $

[greyson-signal]

@bepaald

is the attachment data that follows the AttachmentFrame otherwise correct (complete, properly encrypted and with a correct MAC)?

In the scope of the backup, yes. We essentially write the wrong size, but then write the attachment in it's entirety afterwards, correct MAC and whatnot.

However, in a larger sense, the image is likely badly-encrypted and won't be viewable upon restore. For the same reason we have the wrong attachment size in the DB, we also have a bad DATA_RANDOM value that's used to decrypt the underlying file.

But this is outside of the scope of the backup restoration process. If you can get the right attachment size, you can get through the restoration process. Just don't expect those problem attachments to be viewable.

[g2bb]

@g2bb I'm sorry but yes, as of now, that is the case.

@bepaald

always too short or always too long

No guarantees, but it is likely that the size is almost always longer than it should be.

do you mean the size of the actual attachment data, which is only written into the (encrypted) preceding AttachmentFrame protobuf struct

This one. Specifically, what was written here was the problem:
https://github.com/signalapp/Signal-Android/blob/master/src/org/thoughtcrime/securesms/backup/FullBackupExporter.java#L360

@stonerl No, we don't do message syncing of old messages across linked devices.

@greyson-signal you said you can't automatically fix the backups, but is there a way I can manually do it? I've got a lot of precious memories, and some important info to have that I can't otherwise access

[greyson-signal]

@g2bb It sounds like @bepaald might have something experimental.

[TommyMudd]

Following up from my closed thread. I see that @bepaald has a tool for this, but I'm not clear on how to to utilize it or if it actually applies to my situation. Here's my log file: https://debuglogs.org/401c3de3ac7ab18bd3597dd1f52f6f92de9bc1a1f6dec10940add51ab985d88d

Thanks

[aaronjanse]

However, in a larger sense, the image is likely badly-encrypted and won't be viewable upon restore. For the same reason we have the wrong attachment size in the DB, we also have a bad DATA_RANDOM value that's used to decrypt the underlying file.

Just don't expect those problem attachments to be viewable.

@greyson-signal Would a script that is aware of this bug be able to decrypt the attachments then re-encrypt them properly for Signal?

[rustycanb]

@greyson-signal If the fix is in release 4.50.4, is it feasible to wait for that release, install it on the old device, do a fresh backup on the old device, transfer the new backup file to a new device with 4.50.4 installed and restore without issue?

[greyson-signal]

@aaronjanse

Would a script that is aware of this bug be able to decrypt the attachments then re-encrypt them properly for Signal?

It's a hard question to properly answer without really diving into this very nuanced bug that requires an understanding of our DB schema, encryption schema, and deduping mechanism. But yes, there is a script I could envision that would allow you to get the original media back. It's not something that I think is entirely feasible to put into Signal, and would be better served as an external thing. If it matters, any media affected by this bug would have multiple copies in your message history (like an image that was forwarded to another thread), and at least one of them would be good. So the actual media isn't completely lost, just un-renderable in at least one instance.

@rustycanb

Would a script that is aware of this bug be able to decrypt the attachments then re-encrypt them properly for Signal?

Yes, that's the idea.

[Flupkees]

Has anyone tried 4.50.4? I'm hesitant to update my app to 4.50.4 (by becoming a beta user) to go through this process. If there's one person who can confirm that updating to 4.50.4, recreating the backup and importing it on another phone works (be it 4.49.18 or 4.50.4), I'll try it. I'm tired of having two phones on me and everyone asking me whether I'm a criminal.

[johanw666]

I'm tired of having two phones on me and everyone asking me whether I'm a criminal.

When I was a criminal I often carried 3 or 4 phones. Not using the same burner for everyone made things more difficult. ;-)

Anyway, 4.50 works OK for me. And if you don't want to become a beta tester and just want 4.50.4 you can download it from apkmirror.com (they only have the armv8 version online when I type this, I uploaded the armv7 version myself and its waiting for approval).

[bepaald]

@TommyMudd Yes it looks like you're running into the same issue. If you still have all your messages on a working Signal-installiation, you should probably wait for the fix (or just join the beta and get it immediately) and export a new backup. Otherwise, I guess you should try my program if your message history is important to you. Note that the fix is both untested (on naturally occurring broken backups anyway) and a work in progress (since new information keeps coming in). I'm afraid you will need to run the program under Linux, as I haven't been able to build a windows executable (but no need to install it, for example you could run it off a USB thumb drive). Head on over to https://github.com/bepaald/signalbackup-tools and check out the readme. Let me know how far you get in getting your Linux environment and building the program and then I'll try and talk you through the rest.

@greyson-signal

If it matters, any media affected by this bug would have multiple copies in your message history (like an image that was forwarded to another thread), and at least one of them would be good.

Now that's interesting! Do the duplicate media still have a properly filled in 'data_hash' field in the part table? (I know it was cleared in https://github.com/signalapp/Signal-Android/commit/7f96ee0b62c50bb280d714353a29201a9e46a8ea, but I don't know how that commit relates to the timeline of this bug.) Is the datahash present and the same for identical media and different for different media? Or is the (proper) filesize the only way to limit candidates when trying to find the good copy in the backup file?
Also, just wanted to say thanks for your work on this project in general, and for checking back here regularly!

[greyson-signal]

@bepaald

Do the duplicate media still have a properly filled in 'data_hash' field in the part table?

They would have, but it's likely it was cleared. However, you should be able to find matches by looking at attachment rows that share the same underlying file in the filesystem, which is stored in the data column. And thank you for looking into out-of-app fixes!

[bepaald]

Ok, i think I got it. It is quite an elaborate process though. I thought about automating some more parts of it, but it would be too much work I think, considering it would still be a bit complicated (for some) and not everything _can_ be automated anyway.

Please forgive me if I am not making sense in this post, I've lost some sleep over this problem by now, and for all the time I spent trying to find a way to fix the issue, I've had to spend the same time to actually create a broken backup as I had not actually run into this bug myself.

Here are some complicated instructions for those who can't use official app's fix (because they do not have a working phone/installation anymore):

If you know what you are doing feel free to alter/ignore any of these steps (for example if you're already using Linux, skip step 1):

Step 1: Get a Linux live image, burn it to cdrom/usb drive and boot it, or run it in a virtual machine. There are tons of instruction all over the internet for this. If you have no preference, use this: https://spins.fedoraproject.org/kde/download/index.html (instructions also on that page), at least do not use Ubuntu, we need current versions of the software, not the ancient ones that ship with Ubuntu (if you are already using Ubuntu, there is a dockerfile linked from my github page you could use).

Step 2: Open your menu and open a terminal (called 'konsole' in the Fedora image I linked to in step 1). Install the dependencies, for Fedora type sudo dnf install gcc-g++ cryptopp-devel sqlite-devel which git. It might take a while... when it's done type git clone https://github.com/bepaald/signalbackup-tools to download the sources for the program. Change to that directory by typing cd signalbackup-tools, then build the program by typing sh BUILDSCRIPT.sh.

The bug apparently caused a few issues with the data in the backup file: first of all for one or more attachments, an incorrect size was stored, let's fix that:

Step 3: Call the program on your broken backup file (let's call it 'broken.backup', but obviously change that (and the password) to the actual filename and password): ./signalbackup-tools broken.backup 000001111122222333334444455555 --assumebadframesizeonbadmac.
In the output generated, you will see lines like this: ! CORRECT FRAME_NUMBER:SIZE = 178:78947, hopefully just one, but possibly more.

If you do not care about restoring the corrupted attachments and/or do not have the disk space to store two full copies of your backup file (which would be required for the full procedure) go to step 4a. Otherwise, continue with step 4b.

Step 4a: Run ./signalbackup-tools broken.backup 000001111122222333334444455555 --output fixed.backup --opassword 000001111122222333334444455555 --editattachmentsize 178,78947. If you had more of the 'CORRECT FRAME_NUMBER:SIZE' lines, just keep adding all the numbers (in order, the pairs need to stay together) separated by commas. That's it you are done!, go to step 7.

Step 4b: Now create a new directory: mkdir BROKEN_RAW, then call the program again to fix the bad framesizes: ./signalbackup-tools broken.backup 000001111122222333334444455555 --editattachmentsize 178,78947 --output BROKEN_RAW/. If you had more of the 'CORRECT FRAME_NUMBER:SIZE' lines, just keep adding all the numbers (in order, the pairs need to stay together) separated by commas.
In the output generated, you will see lines like this: Frame has _id = 8, unique_id = 1529478705314. We need these numbers later on.

The program has now written the contents of your entire signal backup file unencrypted to the BROKEN_RAW directory. If you want you can check it out. In this decrypted dump, the wrong framesizes should already be corrected. However, a second problem with this bug is that the attachment data of the files for which the size was incorrect is corrupted. Luckily, this only happens for media that have multiple copies in the backup file, and at least one of them is still good, let's find those:

Step 5: To list the attachments of which the broken ones are duplicates run: ./signalbackup-tools broken.backup 00000111112222233333444445555 --runsqlquery "SELECT _id,unique_id,data_size FROM part WHERE _data IN (SELECT _data FROM part WHERE _id = 8 AND unique_id = 1529478705314)". Note the last two numbers in this command are from the output from step 4. Repeat this command for each of the lines output by the command of step 4.
Each time you run this command, you get a list of attachments that are (or should be) duplicates of the corrupt one, for example:

Executing query: SELECT _id,unique_id,data_size FROM part WHERE _data IN (SELECT _data FROM part WHERE _id = 8 AND unique_id = 1529478705314)
8,1529478705314,78947
11,1529478870610,78947

(Note, more than two duplicates can be listed). These numbers correspond to files in the 'BROKEN_RAW' directory named 'Attachment_8_1529478705314.bin' and 'Attachment_11_1529478870610.bin'. In such a list, at least one of the files is corrupt, and at least one of the files is correct. It's up to you to find out which! If the corruption is severe enough, the corrupt files will probably not be recognized as anything, while the correct ones will most likely be valid media files, for example running:

$ file BROKEN_RAW/Attachment_8_1529478705314.bin BROKEN_RAW/Attachment_11_1529478870610.bin 

Shows

BROKEN_RAW/Attachment_8_1529478705314.bin:  data
BROKEN_RAW/Attachment_11_1529478870610.bin: PNG image data, 1280 x 720, 8-bit/color RGB, non-interlaced

This shows that 'Attachment_11_1529478870610.bin' is the valid correct data and that 'Attachment_8_1529478705314.bin' is corrupted beyond recognition. However I do not know exactly how corrupted the bad attachments are, they may still be recognizable by the file command. In that case, you should just open up all the listed files and determine manually wether they are corrupt or not. Then, simply copy and overwrite the bad attachments with the good ones:

$ cp -vi BROKEN_RAW/Attachment_11_1529478870610.bin BROKEN_RAW/Attachment_8_1529478705314.bin

If you can't figure out which attachments are good and bad, it is not vitally important to fix them. You can still produce a valid, restorable backup file in the next step. In the worst case, a few of the attachments will not render properly when trying to view them.

Step 6: Finally, we pack the contents of the BROKEN_RAW directory up into a new backup-file: ./signalbackup-tools BROKEN_RAW/ --output fixed.backup --opassword 000001111122222333334444455555.

Step 7: Copy the file 'fixed.backup' to the proper place on your phone (and give it a proper name, I think the app needs them to be called 'signal-YYYY-MM-DD-hh-mm-ss.backup'.

That's it! I know it looks like a lot, but it's really not that bad. I can do this in under a minute. I would even happily do it for you, but I can't unless you send me the backup file and password (and don't do that!).

I've made a video of this process starting from step 3, you might be able to follow along with this: https://send.firefox.com/download/4c1e3a662981f37c/#zS1ZWbKvj6kyKoRmhEFUTQ (link is good for 7 days).

If you need more help, please let me know. Right now, i need some sleep.

[Flupkees]

Great to see that you're helping out so much @bepaald! It made me more confident (having a fallback option) to update to 4.50.4 trying to recreate the backup and updating, which I did and now I can use 1 phone again. Also thanks to @greyson-signal for the fix!

[TommyMudd]

As I'm not a Linux user or savvy enough to attempt it, I suppose my last question for now is: has 4.50.4 proved to be successful in transferring these backups that give the related errors? If that's iffy, I can gladly produce a new backup and turn it over to you, @bepaald , just let me know how to safely send to you, and if you have the time.

Thanks

[bepaald]

@TommyMudd If I understand correctly, 4.50.4 will be able to _create_ a working backup, but not restore an existing broken one. It seems @Flupkees, right above your post, has successfully done this. So, if you still have all your messages on your old phone, just update to 4.50.4, create a new backup and import that on your new phone.

[m-terlinde]

I can confirm, that creating a new backup with the new Signal version worked for me. Thanks for all the effort!

[greyson-signal]

For those of you who are in a situation where you still have your old (broken) backup and would like to try to restore it, @alan-signal has made an experimental branch that has been able to restore these broken backups (or at least what we think they look like).

You can reach out to me at [email protected], or via Signal at one of my test numbers ([phone]). I can get you a release-signed build of this branch and we can see if that fixes the problem :+1:

[alan-signal]

If you’re competent at Android development, the source for the fix is at: https://github.com/signalapp/Signal-Android/tree/alan/backup-restoration where the procedure would be to restore the bad backup using that branch, make a new backup, then get back on official releases and restore once more with the new backup.

A debug log from successful or failed attempts to restore the bad backup (either using that branch or an officially signed build of it from Greyson) would be very useful.

[recruiterguy]

@alan-signal I'm hoping you can help me... I have the same issue.
I have an original phone that has my messages in Signal and that does create a backup.
Moving the backup to the new phone they won't successfully restore.
If I'm on 4.50.6, is the solution to put both phones on 4.50.4, create a backup on the original phone and then try to move/restore it on the new phone?
If so, how do I get a copy of 4.50.4 and how would I install that over the newer version on the original phone without erasing everything?

[johanw666]

If I'm on 4.50.6, is the solution to put both phones on 4.50.4

No, the backup fix from 4.50.4 is also present in 4.50.6, so you can keep using that version. If you make a new backup with 4.50.6 on the old phone you should be able to restore that on another phone running 4.50.6.

[recruiterguy]

Yeah - that doesn't seem to work. I'm trying it again now (third time) just to be sure but each version has been 4.50.6 each time.

[recruiterguy]

Okay - that seems to have worked this time. Not sure if it's something related to how I moved the file over or not, but we're back in business. Thanks!