Semi-successful merge Feedback

[eggwhalefrog]

I was able to successfully import the merged backup after manually deleting the notification profile tables using the following SQL queries.

--runsqlquery "DELETE FROM notification_profile" --runsqlquery "DELETE FROM notification_profile_schedule" --runsqlquery "DELETE FROM notification_profile_allowed_members" 

I don't fully recall why I ended up doing that, I assume it was complaining about something regarding that table when I ran the merge command. I found this line https://github.com/bepaald/signalbackup-tools/blob/41c40e85ca28930a8d4f49b1bbf1b39933479a35/signalbackup/customs.cc#L666 so I tried my luck by removing it.

Signal on my phone works without any issues, the problem occurs when I want to link my desktop device. Pretty quickly Signal on my phone crashes:

03-24 00:09:36.320 26537 26624 E AndroidRuntime: FATAL EXCEPTION: signal-JobRunner-1
03-24 00:09:36.320 26537 26624 E AndroidRuntime: Process: org.thoughtcrime.securesms, PID: 26537
03-24 00:09:36.320 26537 26624 E AndroidRuntime: java.lang.AssertionError: RecipientId::168 - No UUID or phone number!
03-24 00:09:36.320 26537 26624 E AndroidRuntime:        at org.thoughtcrime.securesms.recipients.RecipientUtil.toSignalServiceAddress(RecipientUtil.java:54)
03-24 00:09:36.320 26537 26624 E AndroidRuntime:        at org.thoughtcrime.securesms.jobs.MultiDeviceGroupUpdateJob.onRun(MultiDeviceGroupUpdateJob.java:112)
03-24 00:09:36.320 26537 26624 E AndroidRuntime:        at org.thoughtcrime.securesms.jobs.BaseJob.run(BaseJob.java:32)
03-24 00:09:36.320 26537 26624 E AndroidRuntime:        at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:86)
03-24 00:09:36.320 26537 26624 E AndroidRuntime:        at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:49)
03-24 00:09:36.320 26537 26624 E SignalUncaughtException: java.lang.AssertionError: RecipientId::168 - No UUID or phone number!
03-24 00:09:36.320 26537 26624 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.RecipientUtil.toSignalServiceAddress(RecipientUtil.java:54)
03-24 00:09:36.320 26537 26624 E SignalUncaughtException:       at org.thoughtcrime.securesms.jobs.MultiDeviceGroupUpdateJob.onRun(MultiDeviceGroupUpdateJob.java:112)
03-24 00:09:36.320 26537 26624 E SignalUncaughtException:       at org.thoughtcrime.securesms.jobs.BaseJob.run(BaseJob.java:32)
03-24 00:09:36.320 26537 26624 E SignalUncaughtException:       at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:86)
03-24 00:09:36.320 26537 26624 E SignalUncaughtException:       at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:49)

I also tried linking to a fresh desktop instance, that didn't seem to make any difference. As far as I recall I was able to then use my desktop client as expected, but my phone app would no longer open and crash upon startup.

It doesn't look like I still have the crash log from importing the backup without those notification_profile tables deleted, but if needed I can reproduce it.

[bepaald]

Thanks for your report. I'm not sure how the notification profiles would have broken the merge, but deleting seems to have had an effect. Looking at the error in the crash log, I suspect something else however. Maybe you could show the output of signalbackup-tools [input] [password] --runsqlquery "SELECT * FROM recipient WHERE _id = 168"? I think this probably has something to do with the newer tables dealing with distribution_lists or stories. Support for these is definitely not complete yet (can't properly test them as these features aren't actually enabled yet).

If you are in any hurry to get your backup working, I would guess that the above command with SELECT * replaced with DELETE.

It would be very helpful indeed to have a crash log of the unaltered merge file, as well as the output produces by this program from running the merge.

I'll try to investigate a bit later today. Thanks again!

[eggwhalefrog]

Here is the output of the requested query:

 * Executing query: SELECT * FROM recipient WHERE _id = 168
_id|uuid|username|phone|email|group_id|group_type|blocked|message_ringtone|message_vibrate|call_ringtone|call_vibrate|notification_channel|mute_until|color|seen_invite_reminder|default_subscription_id|message_expiration_time|registered|system_given_name|system_family_name|system_display_name|system_photo_uri|system_phone_label|system_phone_type|system_contact_uri|system_info_pending|profile_key|profile_key_credential|signal_profile_name|profile_family_name|profile_joined_name|signal_profile_avatar|profile_sharing|last_profile_fetch|unidentified_access_mode|force_sms_selection|storage_service_key|mention_setting|storage_proto|capabilities|last_session_reset|wallpaper|wallpaper_file|about|about_emoji|extras|groups_in_common|chat_colors|custom_chat_colors_id|badges|pni|distribution_list_id
168|(NULL)|(NULL)|(NULL)|(NULL)|__signal_group__v2__!22fc7b0f72e162cf8723e16bc8f5f4d3943de3a37bfc894571da430d92182bc4|3|0|(NULL)|0|(NULL)|0|(NULL)|0|A150|0|-1|0|0|(NULL)|(NULL)|(NULL)|(NULL)|(NULL)|-1|(NULL)|0|(NULL)|(NULL)|(NULL)|(NULL)|(NULL)|(NULL)|1|0|0|0|TF+3lEZFzxsNyzcog0xnAg==|0|(NULL)|0|(NULL)|(NULL)|(NULL)|(NULL)|(NULL)|(NULL)|0|(NULL)|0|(NULL)|(NULL)|(NULL)

I tried your suggestion and ran --runsqlquery "DELETE FROM recipient WHERE _id = 168 but that causes Signal to crash after the import process unfortunately. This happens after I am asked to setup the PIN:

04-19 18:03:35.131  2622  2818 E SignalUncaughtException: org.thoughtcrime.securesms.database.RecipientDatabase$MissingRecipientException: Failed to find recipient with ID: RecipientId::168
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.lambda$addToCache$2(LiveRecipientCache.java:130)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.$r8$lambda$HU37QnQVO4uJ2wqkYAJZBzAz88k(Unknown Source:0)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache$$ExternalSyntheticLambda3.accept(Unknown Source:4)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.u0.accept(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.f3.accept(Unknown Source:5)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.Iterator$-CC.$default$forEachRemaining(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.E.forEachRemaining(Unknown Source:1)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.c.c0(Unknown Source:4)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.v0.g(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.c.m0(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.l3.forEach(Unknown Source:3)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.addToCache(LiveRecipientCache.java:108)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.lambda$warmUp$3(LiveRecipientCache.java:202)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.$r8$lambda$ymJZipcpDoaCAg5dEDDzJ1eGghQ(Unknown Source:0)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache$$ExternalSyntheticLambda2.run(Unknown Source:4)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.signal.core.util.concurrent.TracingExecutorService$execute$1.run(TracingExecutorService.kt:25)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at java.lang.Thread.run(Thread.java:923)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at [[ ↑↑ Original Trace ↑↑ ]].(:0)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at [[ ↓↓ Inferred Trace ↓↓ ]].(:0)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.signal.core.util.concurrent.TracingExecutor.execute(TracingExecutor.kt:11)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.lambda$addToCache$2(LiveRecipientCache.java:131)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.$r8$lambda$HU37QnQVO4uJ2wqkYAJZBzAz88k(Unknown Source:0)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache$$ExternalSyntheticLambda3.accept(Unknown Source:4)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.u0.accept(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.f3.accept(Unknown Source:5)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.Iterator$-CC.$default$forEachRemaining(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.E.forEachRemaining(Unknown Source:1)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.c.c0(Unknown Source:4)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.v0.g(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.c.m0(Unknown Source:2)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at j$.util.stream.l3.forEach(Unknown Source:3)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.addToCache(LiveRecipientCache.java:108)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.lambda$warmUp$3(LiveRecipientCache.java:202)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache.$r8$lambda$ymJZipcpDoaCAg5dEDDzJ1eGghQ(Unknown Source:0)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.thoughtcrime.securesms.recipients.LiveRecipientCache$$ExternalSyntheticLambda2.run(Unknown Source:4)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at org.signal.core.util.concurrent.TracingExecutorService$execute$1.run(TracingExecutorService.kt:25)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
04-19 18:03:35.131  2622  2818 E SignalUncaughtException:       at java.lang.Thread.run(Thread.java:923)

I also re-ran the merge and have the full output now. Just to be on the safe side before I post it: There shouldn't be any personally identifiable information in there, right? I only skimmed through the log and that doesn't seem to be the case.

This line was probably what made me look into the notification_profile: Error : After sqlite3_step(): UNIQUE constraint failed: notification_profile.name

and here is the crash from importing that backup:

04-19 18:47:23.830 12960 12998 E SignalUncaughtException: java.lang.RuntimeException: An error occurred while executing doInBackground()
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at android.os.AsyncTask$4.done(AsyncTask.java:415)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:383)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at java.util.concurrent.FutureTask.setException(FutureTask.java:252)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at java.util.concurrent.FutureTask.run(FutureTask.java:271)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:305)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at java.lang.Thread.run(Thread.java:923)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException: Caused by: net.zetetic.database.sqlcipher.SQLiteConstraintException: FOREIGN KEY constraint failed (code 787)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteConnection.nativeExecuteForChangedRowCount(Native Method)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteConnection.executeForChangedRowCount(SQLiteConnection.java:767)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteSession.executeForChangedRowCount(SQLiteSession.java:758)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteStatement.executeUpdateDelete(SQLiteStatement.java:70)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteDatabase.executeSql(SQLiteDatabase.java:1994)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteDatabase.execSQL(SQLiteDatabase.java:1951)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at org.thoughtcrime.securesms.backup.FullBackupImporter.processStatement(FullBackupImporter.java:171)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at org.thoughtcrime.securesms.backup.FullBackupImporter.importFile(FullBackupImporter.java:115)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at org.thoughtcrime.securesms.backup.FullBackupImporter.importFile(FullBackupImporter.java:89)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at org.thoughtcrime.securesms.registration.fragments.RestoreBackupFragment$2.doInBackground(RestoreBackupFragment.java:291)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at org.thoughtcrime.securesms.registration.fragments.RestoreBackupFragment$2.doInBackground(RestoreBackupFragment.java:282)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at android.os.AsyncTask$3.call(AsyncTask.java:394)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       at java.util.concurrent.FutureTask.run(FutureTask.java:266)
04-19 18:47:23.830 12960 12998 E SignalUncaughtException:       ... 4 more

[bepaald]

Here is the output of the requested query:

Ah, ok, from the error you posted earlier ("No UUID or phone number!") I was suspecting something else. This recipient is clearly a group, and no group-recipient ever has a uuid or phone number, so I'm sort of confused how the app gets at this point.

I tried your suggestion and ran --runsqlquery "DELETE FROM recipient WHERE _id = 168 but that causes Signal to crash after the import process unfortunately. This happens after I am asked to setup the PIN:

Yes, sorry about that, given that the recipient was an actual group, it's expected that deleting it will cause crashes.

I also re-ran the merge and have the full output now. Just to be on the safe side before I post it: There shouldn't be any personally identifiable information in there, right? I only skimmed through the log and that doesn't seem to be the case.

No, there shouldn't be. But, if you'd feel more comfortable, you could always mail it to me instead of pasting it here.

This line was probably what made me look into the notification_profile: Error : After sqlite3_step(): UNIQUE constraint failed: notification_profile.name

and here is the crash from importing that backup:

Thanks, that was helpful. I now at least (believe I) fully understand the original problem. I was also able to reproduce the problem and see both the error from this program and the same exception when importing. After that, it was an easy fix. I have also tested with the fix and was able to then successfully import a merged backup.

Unfortunately, I still do not see how this problem could have caused the crash you encountered when linking a desktop device. In fact, I think the current (fixed) program should yield the same result as what already tried (the merge from the previous version + delete all notification_profile tables). With the backups I used to verify and fix the problem, I was able to successfully link to a fresh desktop device and saw no crashes.

So there is a good chance these are different issues, you were just unlucky enough to run into two at the same time. Still, if you don't mind, it would be preferred if you tried the merge again with the current version of the program (saving its output), and verifying the same crash still occurs. Though I must admit I have no working theories about this issue at the moment, I will of course keep investigating, and the merge-output may help with that.

Thanks!