search

signalapp / Signal-Android

A private messenger for Android.
https://signal.org
GNU Affero General Public License v3.0
25.56k stars 6.13k forks source link

Signal keeps crashing: table message_fts already exists #13101

Open erjoalgo opened 1 year ago

erjoalgo commented 1 year ago

Bug description

Signal crashes immediately upon startup. I checked the logs from adb logcat, and I see this backtrace:

08-11 18:08:00.626  5846  5885 E SignalUncaughtException: android.database.sqlite.SQLiteException: FullCode: 1 | ErrorCode: 1 | ExtendedErrorCode: 0 | Message: table message_fts already exists | ExtraMessage: , while compiling: CREATE VIRTUAL TABLE message_fts USING fts5(body, thread_id UNINDEXED, content=message, content_rowid=_id)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteConnection.nativePrepareStatement(Native Method)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:925)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteConnection.prepare(SQLiteConnection.java:536)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteSession.prepare(SQLiteSession.java:592)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteProgram.<init>(SQLiteProgram.java:64)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteStatement.<init>(SQLiteStatement.java:38)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteDatabase.executeSql(SQLiteDatabase.java:1991)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteDatabase.execSQL(SQLiteDatabase.java:1900)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.helpers.migration.V175_FixFullTextSearchLink.migrate(V175_FixFullTextSearchLink.kt:18)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.helpers.SignalDatabaseMigrations.migrate(SignalDatabaseMigrations.kt:177)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.SignalDatabase.onUpgrade(SignalDatabase.kt:170)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:403)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at net.zetetic.database.sqlcipher.SQLiteOpenHelper.getReadableDatabase(SQLiteOpenHelper.java:302)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.SignalDatabase.getRawReadableDatabase(SignalDatabase.kt:195)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.SignalDatabase$Companion.hasTable(SignalDatabase.kt:311)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.SignalDatabase.hasTable(SignalDatabase.kt:0)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.JobDatabase.dropTableIfPresent(JobDatabase.java:377)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.JobDatabase.lambda$onOpen$0(JobDatabase.java:148)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.JobDatabase.$r8$lambda$mPCnH21FLj07HGuB-BTTkoK77eM(JobDatabase.java:0)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.thoughtcrime.securesms.database.JobDatabase$$ExternalSyntheticLambda7.run(R8$$SyntheticClass:0)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at java.lang.Thread.run(Thread.java:923)
08-11 18:08:00.626  5846  5885 E SignalUncaughtException:   at org.signal.core.util.concurrent.SignalExecutors$NumberedThreadFactory$1.run(SignalExecutors.java:109)
08-11 18:08:00.627  5846  5889 I SQLiteConnection: Database keying operation returned:0
08-11 18:08:00.647  5846  5917 W JobController: [JOB::084a1674-2d69-40cf-83ec-b5ad959d26e2][RefreshSvrCredentialsJob] Already at the max instance count. Factory limit: -1, Queue limit: 2. Skipping. (Time Since Submission: 1 ms, Lifespan: 86400000 ms, Run Attempt: 1/3, Queue: RefreshKbsCredentials)
08-11 18:08:00.648  5846  5917 I EmojiSearchIndexDownloa: Need to check. It's been 35255292838 ms since the last check.
08-11 18:08:00.649  5846  5917 W JobController: [JOB::a6fecd33-228a-4413-9c70-7f7e382776b8][EmojiSearchIndexDownloadJob] Already at the max instance count. Factory limit: 2, Queue limit: -1. Skipping. (Time Since Submission: 1 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited, Queue: EmojiSearchIndexDownloadJob)
08-11 18:08:00.666  5846  5889 I SQLiteConnection: Database keying operation returned:0
08-11 18:08:00.676  5846  5889 I SignalDatabase: Upgrading database: 155, 201
08-11 18:08:00.693  5846  5885 I JobManager: Successfully flushed.
08-11 18:08:00.694  5846  5885 I Process : Sending signal. PID: 5846 SIG: 9
08-11 18:08:00.755  1356  3337 D ConnectivityService: ConnectivityService NetworkRequestInfo binderDied(NetworkRequest [ TRACK_DEFAULT id=419, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10288 AdministratorUids: [] RequestorUid: 10288 RequestorPackageName: org.thoughtcrime.securesms] ], android.os.BinderProxy@c989b2f)
08-11 18:08:00.756  1356  2163 I ActivityManager: Process org.thoughtcrime.securesms (pid 5846) has died: cch+5 CEM 
08-11 18:08:00.757  1356  1383 I libprocessgroup: Successfully killed process cgroup uid 10288 pid 5846 in 0ms
08-11 18:08:00.757  1356  1519 D ConnectivityService: releasing NetworkRequest [ TRACK_DEFAULT id=419, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10288 AdministratorUids: [] RequestorUid: 10288 RequestorPackageName: org.thoughtcrime.securesms] ] (release request)
08-11 18:08:00.757   624   624 I Zygote  : Process 5846 exited due to signal 9 (Killed)

Steps to reproduce

Actual result: Describe here what happens after you run the steps above (i.e. the buggy behaviour)

Expected result: Describe here what should happen after you run the steps above (i.e. what would be the correct behaviour)

Screenshots

Device info

Device: LG K62 Android version: 11 Signal version: 6.28.6

Link to debug log

Impossible to open signal

aljelly commented 1 year ago

I'm also receiving this crash with the same backtrace (Signal version 6.28.6), except my database version is 163 (migrating to 201). It happens both from the app migrating its database after an update and from restoring from backup on a separate device.

signalbackup-tools reports no issues with database integrity (full check).

This was also happening from an earlier version of Signal so it's likely been happening from an earlier database version also.

erjoalgo commented 1 year ago

This appears to be a relevant excerpt and query of the crash:

CREATE VIRTUAL TABLE message_fts USING fts5(body, thread_id UNINDEXED, content=message, content_rowid=_id)
08-11 19:53:33.046 31431 31486 E AndroidRuntime: android.database.sqlite.SQLiteException: FullCode: 1 | ErrorCode: 1 | ExtendedErrorCode: 0 | Message: table message_fts already exists | ExtraMessage: , while compiling: CREATE VIRTUAL TABLE message_fts USING fts5(body, thread_id UNINDEXED, content=message, content_rowid=_id)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteConnection.nativePrepareStatement(Native Method)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:925)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteConnection.prepare(SQLiteConnection.java:536)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteSession.prepare(SQLiteSession.java:592)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteProgram.<init>(SQLiteProgram.java:64)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteStatement.<init>(SQLiteStatement.java:38)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteDatabase.executeSql(SQLiteDatabase.java:1991)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteDatabase.execSQL(SQLiteDatabase.java:1900)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.database.helpers.migration.V175_FixFullTextSearchLink.migrate(V175_FixFullTextSearchLink.kt:18)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.database.helpers.SignalDatabaseMigrations.migrate(SignalDatabaseMigrations.kt:177)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.database.SignalDatabase.onUpgrade(SignalDatabase.kt:170)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:403)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteOpenHelper.getReadableDatabase(SQLiteOpenHelper.java:302)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.database.SignalDatabase.getSignalReadableDatabase(SignalDatabase.kt:201)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.database.model.AvatarPickerDatabase.getAllAvatars(AvatarPickerDatabase.kt:122)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.avatar.AvatarPickerStorage.cleanOrphans(AvatarPickerStorage.kt:38)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.ApplicationContext.cleanAvatarStorage(ApplicationContext.java:471)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.ApplicationContext.$r8$lambda$ovJzPtEGSgvdzEfbBJQ_xX3JMa4(ApplicationContext.java:0)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.thoughtcrime.securesms.ApplicationContext$$ExternalSyntheticLambda10.run(R8$$SyntheticClass:0)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at java.lang.Thread.run(Thread.java:919)
08-11 19:53:33.046 31431 31486 E AndroidRuntime:    at org.signal.core.util.concurrent.SignalExecutors$NumberedThreadFactory$1.run(SignalExecutors.java:109)
08-11 19:53:34.071  1733  2381 I chatty  : uid=1000(system) Binder:1733_5 expire 8 lines
08-11 19:53:35.141 31544 31599 E AndroidRuntime: FATAL EXCEPTION: signal-bounded-1
08-11 19:53:35.141 31544 31599 E AndroidRuntime: Process: org.thoughtcrime.securesms, PID: 31544
08-11 19:53:35.141 31544 31599 E AndroidRuntime: android.database.sqlite.SQLiteException: FullCode: 1 | ErrorCode: 1 | ExtendedErrorCode: 0 | Message: table message_fts already exists | ExtraMessage: , while compiling: CREATE VIRTUAL TABLE message_fts USING fts5(body, thread_id UNINDEXED, content=message, content_rowid=_id)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteConnection.nativePrepareStatement(Native Method)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:925)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteConnection.prepare(SQLiteConnection.java:536)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteSession.prepare(SQLiteSession.java:592)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteProgram.<init>(SQLiteProgram.java:64)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteStatement.<init>(SQLiteStatement.java:38)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteDatabase.executeSql(SQLiteDatabase.java:1991)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteDatabase.execSQL(SQLiteDatabase.java:1900)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.helpers.migration.V175_FixFullTextSearchLink.migrate(V175_FixFullTextSearchLink.kt:18)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.helpers.SignalDatabaseMigrations.migrate(SignalDatabaseMigrations.kt:177)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.SignalDatabase.onUpgrade(SignalDatabase.kt:170)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:403)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at net.zetetic.database.sqlcipher.SQLiteOpenHelper.getReadableDatabase(SQLiteOpenHelper.java:302)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.SignalDatabase.getRawReadableDatabase(SignalDatabase.kt:195)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.SignalDatabase$Companion.hasTable(SignalDatabase.kt:311)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.SignalDatabase.hasTable(SignalDatabase.kt:0)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.KeyValueDatabase.lambda$onOpen$0(KeyValueDatabase.java:99)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.KeyValueDatabase.$r8$lambda$jefACyoHK4h3lvPI5zn7iBuWxuI(KeyValueDatabase.java:0)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.thoughtcrime.securesms.database.KeyValueDatabase$$ExternalSyntheticLambda0.run(R8$$SyntheticClass:0)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at java.lang.Thread.run(Thread.java:919)
08-11 19:53:35.141 31544 31599 E AndroidRuntime:    at org.signal.core.util.concurrent.SignalExecutors$NumberedThreadFactory$1.run(SignalExecutors.java:109)
08-11 19:53:35.685 31544 31601 E AndroidRuntime: FATAL EXCEPTION: signal-bounded-2
0