signalapp / Signal-Android

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

No messages in view after upgrade to 4.16.3 #7386

Closed johanw666 closed 6 years ago

johanw666 commented 6 years ago

I have:


Bug description

Whan I install 4.16.3 over 4.15.5 and start in, I type in my password, then I see a database upgrade screen, after that I see a screen that invites me to message someone but all my conversations are gone. When I downgrade to 4.15.5 (I just install it, with Xinstaller I can simply install a version with a lower version number) I get all my conversations back. Messaging then also works from 4.15.5.

Whan I reinstall 4.16.3 I don't see the database upgrade screen anymore but my conversations are still not shown.

When I look at the database with an SQL Lite editor I see no changes but I'm studying the source code now to see what should change after a database upgrade.

Edit: I also see nothing that is executed in DatabaseUpgradeActivity.java when the SQLCIPHER constant is filed, is that supposed to be? How can I check in the databaswe which version it thinks it is on?

Link to debug log

https://gist.github.com/anonymous/5ad40b11842a5560d2a7ac191645ccf8

johanw666 commented 6 years ago

I got the impression that the database upgrade didn't work but the version code in the configuration was already upgraded, so I changed in org.thoughtcrime.securesms_preferences.xml the value for last_version_code from 337 back to 333 and reinstalled 4.16.3 but that didn't trigger a new database upgrade. I seem to have missed something.

johanw666 commented 6 years ago

I restored a Titanium backup from this morning and got an error again, this time I got a better crashlog:

https://gist.github.com/anonymous/26820dd04c55fe0abd2dc1ddfa4708b2

moxie0 commented 6 years ago

Why does this say "Signal 4.16.3.1-JW?"

johanw666 commented 6 years ago

Because I built the version myself and I adapted the version number to distinguish it from the official version. The same apk on a different phone (same type of device) did upgrade correctly.

moxie0 commented 6 years ago

Does that mean you've made changes to the source?

BobSilent commented 6 years ago

For me it is the same After I typed in my password, I saw a database upgrade screen, after that I see a screen that invites me to message someone but all my conversations are gone

I could write a new message to someone, but if I now try to write the same person again signal crashes when trying to open the conversation.

https://gist.github.com/anonymous/4c124cc820c8eecd1efafb9a407f6013

Chrome app still working and showing my data, but Android app currently unusable

johanw666 commented 6 years ago

I made some changes to the source but nothing in the database code. I added the old encrypted backup, removed the apk expire, allowed a swipe on ICS instead of JB (it works on my old ICS tablet) and changed the version number.All changed files are at https://mega.nz/#!4Zg1kIaR!A5nIsFp-LD-jibrz1z0qjFVY1GTMBXkq5wG_YMGtyU4

tdussmann commented 6 years ago

To add onto this report, I am experiencing the same behaviour with the official build. After the upgrade to 4.16.3 I logged onto the android app and a very brief db migration screen showed up. Given that I have years of messages in Signal I expected it to run a lot longer than ~10s (maybe it crashed midway through the process?).

Observations:

I am part of the Signal beta program, so I received this update via Play Store. No changes or customized version applied here.

My debug log shows quite a few exceptions now, but I don't have a baseline to compare it to before the upgrade: https://gist.github.com/anonymous/ab4fea5e49df37d3f4001c4be5231e02 An uneducated guess would be that something went seriously wrong with the contacts processing, which could explain the missing and also mixed up message threads from different contacts.

edit oh man, that's really bad, since I am on unrooted, unmodified stock android, I cannot simply downgrade to the older, working version (this has worked before on this same phone with adb uninstall -k and adb install -r -d but apparently it is now never possible to downgrade anymore if the newer app had a certain higher API version? https://plus.google.com/+ArtemRussakovskii/posts/1ZkM87CD51y I get this in logcat: PackageManager: Downgrade detected: Update version code 333 is older than current 337 and it refuses to downgrade with Failure [INSTALL_FAILED_VERSION_DOWNGRADE]

moxie0 commented 6 years ago

@BobSilent @tdussmann It sounds like both of you have screen lock passphrases set in Signal? Did you receive a message after the update but before unlocking the app for the first time? It seems like you're victims of #7390, but I can't be sure since your debug logs don't cover the migration period.

@johanw666 I can't even hazard to guess what's going on with you. Your current state is very wrong, but it looks like you've modified a bunch of stuff, moved backwards and forwards in time, etc. You have too many of your own variables for me to be able to make sense of it.

tdussmann commented 6 years ago

Hmm.. @moxie0 yes, I have a passphrase set for signal (set to retain indefinitely until Signal gets restarted). However I cannot remember receiving a message between updating and unlocking the app, I definitely did not interact with a notification in between, but maybe Signal processed a message while not being started in the background and did not show a notification.

But it sounds a lot as if this is the same issue, with the lost media and mixed conversations + me losing a lot of chats, only having one broken conversation left now... Any chance some data could be recovered by re-migrating? Or is the old data gone after the failed attempt?

moxie0 commented 6 years ago

@BobSilent @tdussmann I've put together an APK series that might help you recover if you haven't done anything to your install since the upgrade. It should hopefully take you back to the place you were at pre-upgrade. That is to say, any messages received between the upgrade and now would be gone, but all previous messages should come back.

First, install this "cleaning" APK over your existing Signal install (do not uninstall first):

https://mega.nz/#!c11hGKYZ!TratUam6GvssC2KGPG3iVx2sKdF67-_y9gKMVqOYpj0

Then launch "Signal cleanup," and it'll display "hello world!" Then install the normal 4.16.4 release over that (do not uninstall the Signal cleanup APK first):

https://mega.nz/#!ctFBQARS!MHVpnx1PK61pevQBccep__3FcgwWv2TdXlWWK8ENYlY

Launch that, enter your password, and it should do the migration. Please immediately capture a debug log after it completes and post here.

@johanw666 I'm afraid that you've modified your install in too many ways for this to work for you.

johanw666 commented 6 years ago

Removing the passphrase and letting 4.16.4 do the upgrade didn't help either. I got the same error. :(

BobSilent commented 6 years ago

@moxie0 just to be sure: my signal data seems to be available (as I can see and use it with Chrome App)

Reiuiji commented 6 years ago

@moxie0 I am also encountering the same issue with the update. I ran the "cleaning" APK over the existing Signal and installed the 4.16.4 update after. I only have three contacts from the update. Here is my debug log for reference. https://gist.github.com/anonymous/f5b90c638d36380216ec94dda2d643b6

tdussmann commented 6 years ago

Aw man, I think I screwed up by doing pm uninstall -k first and trying to revert to the old version with my data... Now there is definitely no userdata left to recover after having started "Signal cleanup", as Signal now just shows a pristine 50MB of data and the welcome screen! I appreciate your effort very much though!

My Chrome App also still shows all the old messages, even after re-attaching it to the android app, however from my understanding those are stored separately and messages are duplicated to both the android and chrome app. @BobSilent since there is no central data store, nor a two way sync between the clients, I think you have to recover your android data with the app by @moxie0

Reiuiji commented 6 years ago

I attempted to recover through titanium backup and I uninstall it by accident. Looks like signal broke after that with https://gist.github.com/Reiuiji/fdb63aa7a04c75fdc51fad17d308fa78

BobSilent commented 6 years ago

@tdussmann thanks for explanation, after I read your sentences I remembered it like that.

@moxie0 for me it did not help, still all messages are gone (followed your instructions with clean apk, and install 4.16.4). A Migration message was shown - quite short. https://gist.github.com/6fffa78cd050e5fb47f7ab81f082e257

johanw666 commented 6 years ago

The cleanup apk didn't help. However, I'm still unsure what is supposed to happen with the upgrade. In DatabaseUpgradeActivity.java nothing happens for the SQLCIPHER constant. I'm now studying the changes in https://github.com/signalapp/Signal-Android/commit/f36b296e2ed211893835372513da57bb135c52c1 but that is a huge commit, any hint would be appreciated.

Edit: tomorrow I'll add a lot of extra logging in SqlCipherMigrationHelper.java and see what that leads to.

Reiuiji commented 6 years ago

I was able to successfully roll back signal to 4.15.5 and recovered my messages for now until SqlCipherMigrationHelper stabilizes. This is very experimental and can potentially mess you up more so proceed with caution. Make sure you have root in order to backup and modify signal data for this.

Back up the data for the signal app data (I use Titanium backup), remove signal (Will delete the SecretKey which 4.16 utilize) in order to downgrade to version 4.15.5 (stable version). Restore the data and go into adb shell to remove the signal.db and journals in the database folder. Start signal and it will load from the data.

moxie0 commented 6 years ago

@BobSilent That log doesn't cover the upgrade period. Can you do the process that I outlined again, while simultaneously running "adb logcat" from a console? You can put some newlines between when you switch from the cleanup apk to the release apk.

moxie0 commented 6 years ago

@johanw666 I wouldn't expect any of this to work for you, you've made too many manual modifications to the data at this point.

@Reiuiji What you've described will most likely irreparably damage your Signal install. I don't recommend anyone doing anything like that if they want to be able to continue running Signal against their existing data. Feel free to experiment, but you and @johanw666 are now in uncharted territory where I unfortunately won't be able to help you.

Reiuiji commented 6 years ago

@moxie0 I agree, this can be damaging to my signal install and I don't recommend it as well. It is only a temp fix for now. I have backups of my data so I can restore and test with later versions of Signal.

Looking through the commit's, SQLCipher + KeyStore will be a great addition to secure the database. I just want to say it needs more time to mature. I went though how it works and found an edge case on missing a secret key for java.security.KeyStore$SecretKeyEntry.getSecretKey() return null (happened when I did a reinstall to 4.16.4).

Now if we are using android secret key's we need to have a way to export the keys for backup purpose and during phone migrate/upgrades. The only way we have in signal is export plaintext backup which needs an update to allow for encrypted backups and option to include mms, secure identities as well.

I hope my feedback helps with the development.

elya5 commented 6 years ago

I have a problem that is probably related to the database upgrade as well and I also use a passcode. Signal was updated and I received a push notification for a group message. When I opened Signal the database upgrade was performed and the message was visible in a new group. So now I have the same group twice but one contains only the new message.

Unfortunately, I do not have the log for the database upgrade because I restarted Signal in the meantime.

johanw666 commented 6 years ago

@moxie0 I have a Titanium backup from just before the update so I can always go back to a "clean" state without 4.16 influence. It misses only a few messages so when I get this fixed I'll have to reset 2 secure sessions but that's all.

moxie0 commented 6 years ago

@elya5 What version?

moxie0 commented 6 years ago

@johanw666 @Reiuiji If you'd like to help debug this, you can:

a) Uninstall Signal completely. b) Restore you backup for a production release, completely unmodified version of Signal 4.15.5 c) Install the 4.16.4 release from here over the 4.15.5 release: https://mega.nz/#!ctFBQARS!MHVpnx1PK61pevQBccep__3FcgwWv2TdXlWWK8ENYlY d) Submit a log of any problems that occur during migration.

Thanks!

johanw666 commented 6 years ago

I just solved the problem: my Signal database had somehow an extra column, I got this exception: E Database: net.sqlcipher.database.SQLiteException: table thread has no column named has_attachment. This column was not present in the database on the phone that upgraded correctly. I have no idea how it came in there.

Manually removing column has_attachment from the table (with an sqllite editor on the PC, removing a column is not that easy on SQLLite I found out) fixed the issue completely. Would you still like me to run this test or is this enough information?

moxie0 commented 6 years ago

@johanw666 Interesting, do you have the full stack trace for that exception?

johanw666 commented 6 years ago

This is generated by a version with some extra logging in the update routine: https://gist.github.com/anonymous/187bc0175751001fb4a0be2fb88acd33

I caught all exceptions in the update routine and handled them by logging them.

elya5 commented 6 years ago

@moxie0 The version is 4.16.3. I think it was bug 7390.

BobSilent commented 6 years ago

@moxie0 here is my log https://gist.github.com/BobSilent/d1ec62f410a5511c274877980e242398

02-05 22:40:13.508 24930 25329 E Database: Error inserting <redacted values> into thread 02-05 22:40:13.508 24930 25329 E Database: net.sqlcipher.database.SQLiteException: table thread has no column named has_attachment: , while compiling: INSERT INTO thread(message_count, has_attachment, last_seen, snippet_type, read, date, unread_count, read_receipt_count, error, recipient_ids, delivery_receipt_count, status, snippet, _id, expires_in, has_sent, type, archived, snippet_cs) VALUES(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?); 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteCompiledSql.native_compile(Native Method) 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteCompiledSql.compile(SQLiteCompiledSql.java:91) 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteCompiledSql.<init>(SQLiteCompiledSql.java:64) 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteProgram.<init>(SQLiteProgram.java:89) 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteStatement.<init>(SQLiteStatement.java:39) 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteDatabase.compileStatement(SQLiteDatabase.java:1589) 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteDatabase.insertWithOnConflict(SQLiteDatabase.java:2060) 02-05 22:40:13.508 24930 25329 E Database: at net.sqlcipher.database.SQLiteDatabase.insert(SQLiteDatabase.java:1930) 02-05 22:40:13.508 24930 25329 E Database: at org.thoughtcrime.securesms.database.helpers.SQLCipherMigrationHelper.copyTable(SQLCipherMigrationHelper.java:205) 02-05 22:40:13.508 24930 25329 E Database: at org.thoughtcrime.securesms.database.helpers.SQLCipherMigrationHelper.migrateCiphertext(SQLCipherMigrationHelper.java:135) 02-05 22:40:13.508 24930 25329 E Database: at org.thoughtcrime.securesms.database.DatabaseFactory.onApplicationLevelUpgrade(DatabaseFactory.java:157) 02-05 22:40:13.508 24930 25329 E Database: at org.thoughtcrime.securesms.DatabaseUpgradeActivity$DatabaseUpgradeTask.doInBackground(DatabaseUpgradeActivity.java:188) 02-05 22:40:13.508 24930 25329 E Database: at org.thoughtcrime.securesms.DatabaseUpgradeActivity$DatabaseUpgradeTask.doInBackground(DatabaseUpgradeActivity.java:169) 02-05 22:40:13.508 24930 25329 E Database: at android.os.AsyncTask$2.call(AsyncTask.java:295) 02-05 22:40:13.508 24930 25329 E Database: at java.util.concurrent.FutureTask.run(FutureTask.java:237) 02-05 22:40:13.508 24930 25329 E Database: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113) 02-05 22:40:13.508 24930 25329 E Database: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588) 02-05 22:40:13.508 24930 25329 E Database: at java.lang.Thread.run(Thread.java:818)

johanw666 commented 6 years ago

@BobSilent that seems to be the same error I had. I might search the history for the database updates to see when this column has been added and when it should have been removed. Since I use Signal from version 1.0.3 that might be some work.

moxie0 commented 6 years ago

@BobSilent @johanw666 Great detective work. It looks like you've been running the same install since October 2015, when there used to be a column named "has_attachment." There's no way to delete a column in sqlite, so it's just hanging around. I'll get a fix together today, thanks!

moxie0 commented 6 years ago

@BobSilent @johanw666 Can you give this 4.16 APK a try? https://mega.nz/#!V4EDCK6Q!IBjzuohQcTjS3rYQzg8wbLxUwDYXEgjHfYNmVZufN44

BobSilent commented 6 years ago

Followed the instruction to first install clean apk and then the new no copy apk worked for me, now my messages from before first upgrade are available.

I also have the install log if needed

johanw666 commented 6 years ago

Signal with https://github.com/signalapp/Signal-Android/commit/0bbe83f8f256219985c61ab2d41ad5a1df5001f3 works great, thanks for supporting us Titanium Backup users anyway. :)

johanw666 commented 6 years ago

On second try, when I try to restore a Titanium Backup from my current installation - which runs fine - on another device (of the same type), I get a crash at startup, any idea what could be wrong here?

02-06 13:13:24.216 W/PartProvider(23183): onCreate()
02-06 13:13:24.433 D/AndroidRuntime(23183): Shutting down VM
02-06 13:13:24.435 E/AndroidRuntime(23183): FATAL EXCEPTION: main
02-06 13:13:24.435 E/AndroidRuntime(23183): Process: org.thoughtcrime.securesms, PID: 23183
02-06 13:13:24.435 E/AndroidRuntime(23183): java.lang.AssertionError: javax.crypto.AEADBadTagException
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.crypto.KeyStoreHelper.unseal(KeyStoreHelper.java:73)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.crypto.DatabaseSecretProvider.getEncryptedDatabaseSecret(DatabaseSecretProvider.java:58)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.crypto.DatabaseSecretProvider.getOrCreateDatabaseSecret(DatabaseSecretProvider.java:29)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.database.DatabaseFactory.<init>(DatabaseFactory.java:121)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.database.DatabaseFactory.getInstance(DatabaseFactory.java:60)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.database.DatabaseFactory.getSmsDatabase(DatabaseFactory.java:75)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.service.ExpiringMessageManager.<init>(ExpiringMessageManager.java:29)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.ApplicationContext.initializeExpiringMessageManager(ApplicationContext.java:151)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.ApplicationContext.onCreate(ApplicationContext.java:86)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.app.Instrumentation.callApplicationOnCreate(Instrumentation.java:1014)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.app.ActivityThread.handleBindApplication(ActivityThread.java:4806)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at de.robv.android.xposed.XposedBridge.invokeOriginalMethodNative(Native Method)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at de.robv.android.xposed.XposedBridge.handleHookedMethod(XposedBridge.java:360)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.app.ActivityThread.handleBindApplication(<Xposed>)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.app.ActivityThread.access$1600(ActivityThread.java:154)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1452)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.os.Handler.dispatchMessage(Handler.java:102)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.os.Looper.loop(Looper.java:234)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.app.ActivityThread.main(ActivityThread.java:5526)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at java.lang.reflect.Method.invoke(Native Method)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:726)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at de.robv.android.xposed.XposedBridge.main(XposedBridge.java:107)
02-06 13:13:24.435 E/AndroidRuntime(23183): Caused by: javax.crypto.AEADBadTagException
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.security.keystore.AndroidKeyStoreCipherSpiBase.engineDoFinal(AndroidKeyStoreCipherSpiBase.java:484)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at javax.crypto.Cipher.doFinal(Cipher.java:1502)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at org.thoughtcrime.securesms.crypto.KeyStoreHelper.unseal(KeyStoreHelper.java:71)
02-06 13:13:24.435 E/AndroidRuntime(23183):     ... 22 more
02-06 13:13:24.435 E/AndroidRuntime(23183): Caused by: android.security.KeyStoreException: Signature/MAC verification failed
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.security.KeyStore.getKeyStoreException(KeyStore.java:636)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.security.keystore.KeyStoreCryptoOperationChunkedStreamer.doFinal(KeyStoreCryptoOperationChunkedStreamer.java:224)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.security.keystore.AndroidKeyStoreAuthenticatedAESCipherSpi$BufferAllOutputUntilDoFinalStreamer.doFinal(AndroidKeyStoreAuthenticatedAESCipherSpi.java:373)
02-06 13:13:24.435 E/AndroidRuntime(23183):     at android.security.keystore.AndroidKeyStoreCipherSpiBase.engineDoFinal(AndroidKeyStoreCipherSpiBase.java:473)
02-06 13:13:24.435 E/AndroidRuntime(23183):     ... 24 more
P-a-d-r-a-i-g commented 6 years ago

I can't access the "cleaning app" at https://mega.nz/#!c11hGKYZ!TratUam6GvssC2KGPG3iVx2sKdF67-_y9gKMVqOYpj0 it's saying "temporary error" for the past hour. Can you upload it again please, and provide an hash of the file please.

johanw666 commented 6 years ago

I've uploaded it on https://mega.nz/#!9UJGxYSI!5dVBtrnwrXAOXHt8xRrH_NjHZZvgUSLPSapfxKBcPck

C:\>md5sum Signal-4.16.4-cleanup.apk
b532f2ebcd141f51c15255acbdee389b *Signal-4.16.4-cleanup.apk
bill-mcgonigle commented 6 years ago

@johanw666 - my md5sum matches but LineageOS 14.1 says the archive is corrupt?

@Reiuiji - holy cow, man, do I owe you a beer. I had a phone problem that required wiping to factory and rebuilding and I nearly lost years' worth of messages relating to clients and a divorce proceeding because of this change. I "knew" my regular backups were sufficient because I've restored Signal many times before but never expected a code change that would result in complete dataloss. Until there is a reliable way native way to do backups I've locked my version to 14.5.5 and will live with two weeks' dataloss as a hard-knocks lesson. I get the risk that's being solved with a hardware key but there are code risks and social risks and the latter greatly outweighs the former for me in this case. It'll be great to have both covered in the future.

BlackLotus commented 6 years ago

@bill-mcgonigle and @reiuiji so I guess https://github.com/signalapp/Signal-Android/issues/7457#comment-370179250 didn't work for you?

Reiuiji commented 6 years ago

@BlackLotus Looking at #7457, I had a similar issue that I had to clear it completely and restore with one of my Titanium Backups. I am sticking to 14.5.5 for the time being until I feel confident with the KeyStore system and backup integration on my main phone.