Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failure to import database into android after merging with desktop #233

Closed
james-callahan opened this issue Aug 22, 2024 · 12 comments
Closed
Labels
not a bug Not a bug in the program, not a feature request. Something else.

Comments

@james-callahan
Copy link

I ran a migration from an old signal backup from 2022 + a recent signal desktop database:

signalbackup-tools signal-2022.backup  --importfromdesktop -o merged.backup

FWIW the database seems to be at 146:

Database version: 146

I note that the merge was full of warnings, here are samples of each one:

Trying to match conversation (1/37) (type: private)
 - Importing 254 messages into thread._id 5
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Unhandled message type 'delivery-issue'. Skipping message. (this warning will be shown only once)
[Error]: During sqlite3_prepare_v2(): no such column: message_ranges
         -> Query: "UPDATE mms SET message_ranges = ? WHERE rowid = ?"
Trying to match conversation (12/37) (type: group)
 - Importing 4345 messages into thread._id 1
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Error]: Asked to find recipient._id for empty uuid. Refusing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
Trying to match conversation (9/37) (type: group)
 - Importing 151 messages into thread._id 4
[Warning]: Unsupported message type 'group-v2-change'. Skipping... (this warning will be shown only once)
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
[Warning]: Failed to find recipient for uuid: 04e9xxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
[Warning]: Failed to find recipient for mention. Skipping.
[Warning]: Failed to find recipient for uuid: 04e9xxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
[Warning]: Failed to find recipient for phone: +61xxxxxxxxx
[Error]: Failed to set address of incoming group message. Skipping
[Warning]: Table 'mms' does not contain any column 'view_once'. Removing
Trying to match conversation (26/37) (type: private)
[Warning]: Failed to find recipient for uuid: f0c8xxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
[Warning]: Chat partner was not found in recipient-table. Skipping. (id: f0
[Warning]: Failed to find recipient for uuid: __signal_group__v2__!61b2xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
[Warning]: Chat partner was not found in recipient-table. Skipping. (id: __signal_group__v2__!61b2

Nevertheless, I attempted to import the output database into signal on my android phone.
The signal app crashed.
Looking via adb logcat I see:

08-22 12:07:57.602 21705 21763 E BaseJob : Encountered a fatal exception. Crash imminent.
08-22 12:07:57.602 21705 21763 E BaseJob : java.lang.IllegalStateException: Tried to call getSelf() before local data was set!
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.recipients.LiveRecipientCache.getSelf(LiveRecipientCache.java:159)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.recipients.Recipient$Companion.self(Recipient.kt:1028)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.database.MessageTable.insertMessageInbox(MessageTable.kt:2613)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.database.MessageTable.insertMessageInbox$default(MessageTable.kt:2579)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.releasechannel.ReleaseChannel.insertReleaseChannelMessage(ReleaseChannel.kt:77)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.releasechannel.ReleaseChannel.insertReleaseChannelMessage$default(ReleaseChannel.kt:24)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.jobs.StoryOnboardingDownloadJob.onRun(StoryOnboardingDownloadJob.kt:128)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.jobs.BaseJob.run(BaseJob.java:31)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:88)
08-22 12:07:57.602 21705 21763 E BaseJob : 	at org.thoughtcrime.securesms.jobmanager.JobRunner.run(JobRunner.java:51)

Hopefully that's enough for you to help out.


At least for the view_once warnings, perhaps it would help if there was a way to run migrateDatabase on the 2022 dump before merging it?

@bepaald
Copy link
Owner

bepaald commented Aug 22, 2024

Hi!

Thanks for reporting, sorry to hear you are having trouble. I don't see anything obvious in those warnings and errors that would really cause the backup to be corrupt. The only really ugly error is this one:

[Error]: During sqlite3_prepare_v2(): no such column: message_ranges
         -> Query: "UPDATE mms SET message_ranges = ? WHERE rowid = ?"

Which I will try to find and fix shortly. But that too would not cause a failure to import.

In fact, I'm not too sure this is a bug caused by the desktop-import at all. There are known problems with restoring older backups in Signal (specifically backups from 2022 even, see Signal-Android#13506).

Does the crash happen quickly, or does it actually show some percentage of restoring messages before? If you look at the full logcat output, do you see (a lot of) database migrations running and completing successfully? (I suspect it doesn't even start those).

Really the way to go here is to restore the original (untouched by this program) 2022 backup on Signal and verify it works correctly. If it does, there is indeed a bug in this tool, but at least you'll have a fully migrated up-to-date backup to import into. If it still crashes, the problem is not this tool and you should probably open an issue with Signal-Android.

At least for the view_once warnings, perhaps it would help if there was a way to run migrateDatabase on the 2022 dump before merging it?

As per the note in that file:

// NOTE this function does not perform a full migrate to a (necessarily) working backup file. Its just enough for this programs exportHTML() function.

I do not necessarily plan to support proper full migrations, because:

  • While most migrations are fairly simple, some can't be done by this tool, they would require either server communication or access to the Android OS on which it is (should be) running.
  • Doing full migrations would simply mean duplicating all migration code from Signal, which I feel is pointless.

The obvious way to migrate your database, as mentioned above, is to let Signal do it.

So, please attempt to restore the 2022 backup and let me know if the results are different. If so, I'd say try to import the desktop data into the new backup and let me know.

Thanks!

@james-callahan
Copy link
Author

Does the crash happen quickly, or does it actually show some percentage of restoring messages before? If you look at the full logcat output, do you see (a lot of) database migrations running and completing successfully? (I suspect it doesn't even start those).

It got quite far: successfully importing some 80000 messages or so including media. Then the app crashed.
And then when I try and start the android application again, it fails with a few errors, including the one I pasted above.

Are there any logs in particular I should try and grab for you?


Also, is there any way to import the messages/contacts that were missing from the original android backup? I assume from the "skipped" warnings that those conversations would get dropped?

@bepaald
Copy link
Owner

bepaald commented Aug 22, 2024

It got quite far: successfully importing some 80000 messages or so including media. Then the app crashed.
And then when I try and start the android application again, it fails with a few errors, including the one I pasted above.

Are there any logs in particular I should try and grab for you?

No, not that I can think of, though I'm not an expert on these logs. But definitely all the exceptions, and maybe the ones from the initial crash are more important than the ones from restarting (though they may be the same). Still, I'd really like to hear that importing the original backup, without imported desktop messages, works correctly.

Also, is there any way to import the messages/contacts that were missing from the original android backup? I assume from the "skipped" warnings that those conversations would get dropped?

No, the contacts must exist in the backup, it is not possible to create valid contacts from the desktop data (that I know of). If no thread exists with some contact one is created, that is no problem. For exporting to HTML there is the --addincompletedataforhtmlexport which does add missing contacts, but just like with migrateDatabase this is just for exporting to HTML and does not produce a valid backup. (Also see the README, last paragraph of the import from desktop section).

Where possible, the way to get around this is again, to import the original backup into signal, get it updated and get as many of your contacts in there as you can, then export a new backup and try again.

@james-callahan
Copy link
Author

james-callahan commented Aug 22, 2024

No, not that I can think of, though I'm not an expert on these logs. But definitely all the exceptions, and maybe the ones from the initial crash are more important than the ones from restarting (though they may be the same). Still, I'd really like to hear that importing the original backup, without imported desktop messages, works correctly.

I did the merge again with --deleteattachments, cleared all data and did the import again. It crashed after reading most/all of the messages:

08-22 19:08:12.582  8445  8789 I SignalDatabaseMigration: Successfully completed migration for version 188 in 1839 ms
08-22 19:08:12.583  8445  8789 I SignalDatabaseMigration: Running migration for version 189: V189_CreateCallLinkTableColumnsAndRebuildFKReference. Foreign keys: false
08-22 19:08:12.600  8445  8789 I SignalDatabaseMigration: Successfully completed migration for version 189 in 16 ms
08-22 19:08:12.600  8445  8789 I SignalDatabaseMigration: Running migration for version 190: V190_UniqueMessageMigration. Foreign keys: false
08-22 19:08:12.600  8445  8789 I SignalDatabaseMigration: Successfully completed migration for version 190 in 0 ms
08-22 19:08:12.600  8445  8789 I SignalDatabaseMigration: Running migration for version 191: V191_UniqueMessageMigrationV2. Foreign keys: false
08-22 19:08:12.617   531  4710 D StNfcHal: (#07A36) Rx 60 07 01 e6 
08-22 19:08:12.620   799   799 I BufferQueueProducer: [org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640](this:0xb400006ecd6405c8,id:-1,api:0,p:-1,c:799) queueBuffer: fps=60.99 dur=1000.20 max=16.98
 min=15.82
08-22 19:08:12.632   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098947, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:12.732   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098948, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:12.750  8445  8789 E SQLiteLog: (267) statement aborts at 10: [WITH needs_delete AS (
08-22 19:08:12.750  8445  8789 E SQLiteLog:         SELECT
08-22 19:08:12.750  8445  8789 E SQLiteLog:           _id
08-22 19:08:12.750  8445  8789 E SQLiteLog:         FROM
08-22 19:08:12.750  8445  8789 E SQLiteLog:           message M
08-22 19:08:12.750  8445  8789 E SQLiteLog:         WHERE
08-22 19:08:12.750  8445  8789 E SQLiteLog:           _id > (
08-22 19:08:12.750  8445  8789 E SQLiteLog:             SELECT
08-22 19:08:12.750  8445  8789 E SQLiteLog:               min(_id)
08-22 19:08:12.750  8445  8789 E SQLiteLog:             FROM
08-22 19:08:12.750  8445  8789 E SQLiteLog:         
08-22 19:08:12.845   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098949, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:12.960   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098950, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:13.030   531  4710 D StNfcHal: (#07A37) Rx 60 07 01 e6 
08-22 19:08:13.072   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098951, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:13.161  8445  8511 D MemoryTracker: The system decreased our app JVM heap from 22065117 (21.04 MiB) to 21622749 (20.62 MiB)
08-22 19:08:13.162  8445  8511 D MemoryTracker: Used memory has decreased from 13260784 (12.65 MiB) to 11401200 (10.87 MiB)
08-22 19:08:13.172   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098952, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:13.273   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098953, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:13.289   778   828 I libPerfCtl: xgfGetFPS pid:8445 fps:60
08-22 19:08:13.289   778   828 I libPerfCtl: xgfGetFPS pid:19869 fps:-1
08-22 19:08:13.382   799   799 I BufferQueueProducer: [FramebufferSurface](this:0xb400006e7d4f87e0,id:-1,api:1,p:799,c:799) queueBuffer: fps=60.93 dur=1001.12 max=21.07 min=13.51
08-22 19:08:13.383   767   767 I hwcomposer: [HWCDisplay] [Display_0 (type:1)] fps:60.919945,dur:1001.31,max:21.27,min:13.32  
08-22 19:08:13.387   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098954, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:13.404  1080  1215 D ULogGuard: Monitoring: 14 threads, 0 requests, 0 time-bombs; 47 guards. ResetFlags = 0x7
08-22 19:08:13.443   531  4710 D StNfcHal: (#07A38) Rx 60 07 01 e6 
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler: Database 'signal.db' corrupted!
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler: [sqlite] FullCode: 267 | ErrorCode: 11 | ExtendedErrorCode: 1 | Message: database disk image is malformed | ExtraMessage: null
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler: Diagnostic results:
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler:   ===== PRAGMA integrity_check (same-connection) =====
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler: ok
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler: 
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler: ===== PRAGMA cipher_integrity_check (same-connection) =====
08-22 19:08:13.455  8445  8789 E SqlCipherErrorHandler: 
08-22 19:08:13.455  8445  8789 W SearchTable: [fullyResetTables] Dropping tables and triggers...
08-22 19:08:13.457  8445  8789 W SearchTable: [fullyResetTables] Recreating table...
08-22 19:08:13.458  8445  8789 W SearchTable: [fullyResetTables] Recreating triggers...
08-22 19:08:13.460  8445  8789 I Job     : [JOB::dd1c71d8-d738-4281-b3ed-b69b616285e9][RebuildMessageSearchIndexJob] onSubmit() (Time Since Submission: 0 ms, Lifespan: Immortal, Run Attempt: 1/3, Queue: RebuildMessageSearchIndex)
08-22 19:08:13.461  8445  8789 W SearchTable: [fullyResetTables] Done. Index will be rebuilt asynchronously)
08-22 19:08:13.461  8445  8485 I JobSchedulerScheduler: JobScheduler enqueue of  (0)
08-22 19:08:13.462  8445  8789 I JobManager: onConstraintMet(DataRestoreConstraint)
08-22 19:08:13.463  8445  8500 I JobRunner: [JOB::dd1c71d8-d738-4281-b3ed-b69b616285e9][RebuildMessageSearchIndexJob][3] Running job. (Time Since Submission: 3 ms, Lifespan: Immortal, Run Attempt: 1/3, Queue: RebuildMessageSearchInd
ex)
08-22 19:08:13.464  1483  1501 D AlarmManagerService: inside native alarm timerfd set Alarm Type = 2
08-22 19:08:13.464  1483  1501 D AlarmManagerService: inside native alarm timerfd set Alarm Type = 2
08-22 19:08:13.471  8445  8445 E SignalUncaughtException: java.lang.IllegalStateException: Cannot perform this operation because there is no current transaction.
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteSession.throwIfNoTransaction(SQLiteSession.java:950)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteSession.endTransaction(SQLiteSession.java:402)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at net.zetetic.database.sqlcipher.SQLiteDatabase.endTransaction(SQLiteDatabase.java:572)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at org.signal.core.util.SQLiteDatabaseExtensionsKt.withinTransaction(SQLiteDatabaseExtensions.kt:23)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at org.thoughtcrime.securesms.database.helpers.SignalDatabaseMigrations.migrate(SignalDatabaseMigrations.kt:216)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at org.thoughtcrime.securesms.database.SignalDatabase.onUpgrade(SignalDatabase.kt:176)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at org.thoughtcrime.securesms.database.SignalDatabase$Companion.runPostBackupRestoreTasks(SignalDatabase.kt:289)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at org.thoughtcrime.securesms.restore.RestoreRepository$restoreBackupAsynchronously$2.invokeSuspend(RestoreRepository.kt:64)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:111)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:99)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:811)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:715)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:702)
08-22 19:08:13.471  8445  8445 E SignalUncaughtException:       Suppressed: kotlinx.coroutines.internal.DiagnosticCoroutineContextException: [StandaloneCoroutine{Cancelling}@95d8dec, Dispatchers.Main.immediate]
08-22 19:08:13.480  8445  8500 I SearchTable: Re-indexing. Operating on ID's 1-49459 in steps of 10000.
08-22 19:08:13.480  8445  8500 I SearchTable: Reindexing ID's [1, 10001)
08-22 19:08:13.483  8445  8445 I JobManager: Successfully flushed.
08-22 19:08:13.484  8445  8445 E AndroidRuntime: FATAL EXCEPTION: main
08-22 19:08:13.484  8445  8445 E AndroidRuntime: Process: org.thoughtcrime.securesms, PID: 8445
08-22 19:08:13.484  8445  8445 E AndroidRuntime: java.lang.IllegalStateException: Cannot perform this operation because there is no current transaction.
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at net.zetetic.database.sqlcipher.SQLiteSession.throwIfNoTransaction(SQLiteSession.java:950)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at net.zetetic.database.sqlcipher.SQLiteSession.endTransaction(SQLiteSession.java:402)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at net.zetetic.database.sqlcipher.SQLiteDatabase.endTransaction(SQLiteDatabase.java:572)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at org.signal.core.util.SQLiteDatabaseExtensionsKt.withinTransaction(SQLiteDatabaseExtensions.kt:23)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at org.thoughtcrime.securesms.database.helpers.SignalDatabaseMigrations.migrate(SignalDatabaseMigrations.kt:216)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at org.thoughtcrime.securesms.database.SignalDatabase.onUpgrade(SignalDatabase.kt:176)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at org.thoughtcrime.securesms.database.SignalDatabase$Companion.runPostBackupRestoreTasks(SignalDatabase.kt:289)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at org.thoughtcrime.securesms.restore.RestoreRepository$restoreBackupAsynchronously$2.invokeSuspend(RestoreRepository.kt:64)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:111)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:99)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:811)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:715)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:702)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at [[ ↑↑ Original Trace ↑↑ ]].(:0)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at [[ ↓↓ Exception Message ↓↓ ]].(:0)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        at Cannot perform this operation because there is no current transaction..(:0)
08-22 19:08:13.484  8445  8445 E AndroidRuntime:        Suppressed: kotlinx.coroutines.internal.DiagnosticCoroutineContextException: [StandaloneCoroutine{Cancelling}@95d8dec, Dispatchers.Main.immediate]
08-22 19:08:13.486  1483  9221 E ActivityManager: App crashed on incremental package org.thoughtcrime.securesms which is 100% loaded.
08-22 19:08:13.491  1483  9221 I mtkpower_client: [Legacy][PowerHal_Wrap_notifyAppState] org.thoughtcrime.securesms/org.thoughtcrime.securesms pid=8445 state:3
08-22 19:08:13.491  1483  9221 I game_scn: collectForegroundAppList packName=org.thoughtcrime.securesms, actName=org.thoughtcrime.securesms, pid=8445, uid=10214, state:DEAD
08-22 19:08:13.491   778   852 I libPowerHal: [perfNotifyAppState] pack:org.thoughtcrime.securesms, act:org.thoughtcrime.securesms, state:3, pid:8445, uid:10214, fps:60
08-22 19:08:13.491   778   852 I libPowerHal: [perfNotifyAppState] pack:org.thoughtcrime.securesms, pid:8445, STATE_DEAD
08-22 19:08:13.491   778   852 D RilUtility: notify_rild_crash_pid_set certPid:-1, crash:8445, scn:0x0
08-22 19:08:13.493  1483  8983 I DropBoxManagerService: add tag=data_app_crash isTagEnabled=true flags=0x2
08-22 19:08:13.494  1483  9221 W ActivityTaskManager:   Force finishing activity org.thoughtcrime.securesms/.restore.RestoreActivity
08-22 19:08:13.497  1483  9221 I PowerHalWrapper: <amsBoostResume> last:org.thoughtcrime.securesms, next:org.thoughtcrime.securesms 
08-22 19:08:13.497   799   799 I SurfaceFlinger: operator()(), mtkRenderCntDebug 1098955, screenshot (org.thoughtcrime.securesms/org.thoughtcrime.securesms.restore.RestoreActivity#96640)
08-22 19:08:13.497  1483  8983 W AES     : Exception Log handling...
08-22 19:08:13.497  1483  8983 W AES     : Skipped - do not care third party apk

@james-callahan
Copy link
Author

james-callahan commented Aug 22, 2024

Looks like this could be the same as signalapp/Signal-Android#13034 ?
Which includes several other people that tried out signalbackup-tools

@bepaald
Copy link
Owner

bepaald commented Aug 22, 2024

I did the merge again with --deleteattachments, cleared all data and did the import again. It crashed after reading most/all of the messages:

OK, interesting, I will take a closer look later, I'm at work right now.

Looks like this could be the same as signalapp/Signal-Android#13034 ?
Which includes several other people that tried out signalbackup-tools

Yes it does very much look like #13034. It is important to note those other people appear to have used this program to verify the backup integrity and/or attempt a fix, not that this program introduced the problem.

I your case, that's still to be determined, so one last time: you have to attempt to restore the original backup. Only if you do that, can we be sure you are running into a signal bug, and it is not this tool that is injecting bad data into the backup file.

If the bug turns out to be in Signal, I will still try to find out what's causing it and see if I can alter the backups so that Signals migration doesn't choke on it (if I can), but we need to know whose bug this is.

@james-callahan
Copy link
Author

I your case, that's still to be determined, so one last time: you have to attempt to restore the original backup. Only if you do that, can we be sure you are running into a signal bug, and it is not this tool that is injecting bad data into the backup file.

I attempted to restore from the original backup and got a similar crash.
So yeah, apparently not this tool's fault at all!

If the bug turns out to be in Signal, I will still try to find out what's causing it and see if I can alter the backups so that Signals migration doesn't choke on it (if I can), but we need to know whose bug this is.

What else can I provide to help?

@bepaald
Copy link
Owner

bepaald commented Sep 2, 2024

I attempted to restore from the original backup and got a similar crash.
So yeah, apparently not this tool's fault at all!

Excellent!

What else can I provide to help?

Well, I looked at the code where Signal crashes, but don't see anything incorrect about it. I've tried running it on my databases manually and that seems to work fine (though it's artificial data, as I didn't have any doubles in my database (this specific migration deals with duplicate messages)).

I've begun re-implementing the migration functions from Signal, I hope that that will either work (successfully migrate) or allow for better error reporting. It's a fairly big job, so it'll take a while (if I can get it done at all).

When it's done, I'm going to ask you to run the tool with some specific options on your backup and let me know the results if that's ok. Then I'll probably make some changes and ask again, repeatedly, until we figure out what or we give up.

@bepaald bepaald added the not a bug Not a bug in the program, not a feature request. Something else. label Sep 11, 2024
@bepaald
Copy link
Owner

bepaald commented Sep 11, 2024

So I've implemented the migrations I linked to in my previous post, from v132 up to v191. Luckily most were very easy, just adding or renaming a single column in one of the database tables. Others were more difficult. It is very possible I've made some mistake in there, from a simple copy-paste error to actually misinterpreting what the intention was. Also, there was at least 1 situation were I needed to bail since the original version needed to talk to the server at that point.

I don't know how big of chance at succeeding this has, but maybe it'll work, or maybe it'll give us a clue what's happening in Signal. You could run with:

$ signalbackup-tools [input] [passphrase] --migrate_to_191 -o [output] [optional_new_output_passphrase]

And see if it works. If you see any errors during migrating, let me know. If everything looks good, (like this:

 *** Starting log: 2024-09-11 15:59:00 *** 
signalbackup-tools (./signalbackup-tools) source version 20240910.222304
BACKUPFILE VERSION: 0
BACKUPFILE SIZE: 25027997
COUNTER: 1483570187
Reading backup file: 100.0%...
Read entire backup file...
Reading backup file: 100.0%... done!
Database version: 134
To 135
To 136
To 137
To 138
To 139
To 140
To 141
To 142
To 143
To 144
To 145
To 146
To 147
To 148
To 149
To 150
To 151
To 152
To 153
To 154
To 155
To 156
To 157
To 158
To 159
To 160
To 161
To 162
To 163
To 164
To 165
To 166
To 167
To 168
To 169
To 170
To 171
To 172
To 173
To 174
To 175
To 176
To 177
To 178
To 179
To 180
To 181
To 182
To 183
To 184
To 185
Checking foreign key constraints... ok
Checking database integrity (full)... ok
To 186
To 187
To 188
To 189
To 190
To 191
Checking foreign key constraints... ok
Checking database integrity (full)... ok

), you might attempt to restore the backup on a phone. Please do this on the original, unaltered backup, and do not attempt any other functions simultaneously on the same file (like importing from desktop or deleting attachments). I'm curious what's going to happen, let's see how far we get.

@james-callahan
Copy link
Author

I think that worked! Importing the migrated backup took me to the enter-a-phone number screen. I didn't enter my phone number as I wasn't sure if that would break a future migration/tell my contacts.

I'm guessing I should merge in the desktop messages now and do the phone number step?

@bepaald
Copy link
Owner

bepaald commented Sep 13, 2024

I think that worked! Importing the migrated backup took me to the enter-a-phone number screen. I didn't enter my phone number as I wasn't sure if that would break a future migration/tell my contacts.

I'm guessing I should merge in the desktop messages now and do the phone number step?

Cool!

I think the phone-number screen is normal after restoring a backup, it's been a while since I've done it. I would definitely finish setting up Signal, enter phone number and do the SMS verification, and make sure everything is working and all your data is there.

Then export a new backup (it will be around version 240, not sure exactly), copy it from your phone to your computer and attempt to import the Signal Desktop messages into that new backup.

@james-callahan
Copy link
Author

Then export a new backup (it will be around version 240, not sure exactly), copy it from your phone to your computer and attempt to import the Signal Desktop messages into that new backup.

That worked... sort of.

Upon restoring this new backup; I did have (most of) my messages, but it did send a "has a new safety number" notification to all my contacts.

In any case, I'm all set up on this new device now, so thank you!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
not a bug Not a bug in the program, not a feature request. Something else.
Projects
None yet
Development

No branches or pull requests

2 participants