Signal won't start after upgrade to 1.15.0

[jasonku]

• I have searched open and closed issues for duplicates

Bug description

I can no longer launch Signal Desktop after upgrading to 1.15.0

Steps to reproduce

1. Upgrade Signal to 1.15.0
2. Try to start it.

Actual result:

See this

See this in logs

~/Library/Application Support/Signal/logs]$ tail log.log
{"name":"log","hostname":"karpos.local","pid":10979,"level":50,"msg":"Uncaught error or unhandled promise rejection: Error: SQLITE_NOTADB: file is not a database","time":"2018-08-04T05:08:49.220Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11599,"level":30,"msg":"app ready","time":"2018-08-04T05:11:00.131Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11599,"level":30,"msg":"Ensure attachments directory exists","time":"2018-08-04T05:11:00.146Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11599,"level":50,"msg":"Uncaught error or unhandled promise rejection: Error: SQLITE_NOTADB: file is not a database","time":"2018-08-04T05:11:00.156Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11702,"level":30,"msg":"app ready","time":"2018-08-04T05:12:18.085Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11702,"level":30,"msg":"Ensure attachments directory exists","time":"2018-08-04T05:12:18.096Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11702,"level":50,"msg":"Uncaught error or unhandled promise rejection: Error: SQLITE_NOTADB: file is not a database","time":"2018-08-04T05:12:18.106Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11928,"level":30,"msg":"app ready","time":"2018-08-04T05:15:50.402Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11928,"level":30,"msg":"Ensure attachments directory exists","time":"2018-08-04T05:15:50.416Z","v":0}
{"name":"log","hostname":"karpos.local","pid":11928,"level":50,"msg":"Uncaught error or unhandled promise rejection: Error: SQLITE_NOTADB: file is not a database","time":"2018-08-04T05:15:50.427Z","v":0}

Expected result:

Expect to see a window and messages.

Screenshots

Platform info

Signal version:

1.15.0

Operating System:

Linked device version:

iPhone SE, iOS version 1.3.3

Link to debug log

Can send log.log files privately by request.

[2-4601]

I believe this question suits here aswell:

@scottnonnenberg-signal wrote:
When you get that error message, the SQLCipher decryption key is incorrect. Can you talk about the history of Signal Desktop on that machine? Had it started migrating messages over?

[jasonku]

@2-4601 @scottnonnenberg-signal

How may I check whether it had already started migrating messages over?

I will note that around this time I ran out of disk space on my machine, so maybe that had something to do with it.

[benmayne]

I just had this happen on my ubuntu 16.04 machine with lots of old messages to transfer over

benmayne@ben-laptop ~ $ /opt/Signal/signal-desktop
NODE_ENV production
NODE_CONFIG_DIR /opt/Signal/resources/app.asar/config
NODE_CONFIG {}
ALLOW_CONFIG_MUTATIONS undefined
HOSTNAME undefined
NODE_APP_INSTANCE undefined
SUPPRESS_NO_CONFIG_WARNING undefined
Set Windows Application User Model ID (AUMID) { appUserModelId: 'org.whispersystems.signal-desktop' }
userData: /home/benmayne/.config/Signal
making app single instance
{"name":"log","hostname":"ben-laptop","pid":5257,"level":30,"msg":"app ready","time":"2018-08-08T02:36:34.851Z","v":0}
{"name":"log","hostname":"ben-laptop","pid":5257,"level":30,"msg":"Ensure attachments directory exists","time":"2018-08-08T02:36:34.856Z","v":0}
{"name":"log","hostname":"ben-laptop","pid":5257,"level":50,"msg":"Uncaught error or unhandled promise rejection: Error: SQLITE_NOTADB: file is not a database","time":"2018-08-08T02:36:34.860Z","v":0}

I can't tell what my version is, but I just got here from apt-get update.

benmayne@ben-laptop ~ $ uname -a
Linux ben-laptop 4.15.18-041518-generic #201804190330 SMP Thu Apr 19 07:34:21 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
benmayne@ben-laptop ~ $ lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 16.04.5 LTS
Release:	16.04
Codename:	xenial

[scottnonnenberg-signal]

@benmayne @jasonku

The configuration directories listed here are where Signal Desktop stores its data: https://github.com/signalapp/Signal-Desktop/blob/development/CONTRIBUTING.md#the-staging-environment

In that folder, there is a config.json, and the 'key' key in it is where the SQLCipher decryption key is kept. Somehow, it seems that the decryption key has been lost. What do you see in config.json right now? Is there anything interesting in the logs directory the config directories?

Anyone running into this should probably contact support@signal.org. If you have backups of that config directory, maybe that will have the decryption key, or maybe it's something simple and we can recover things. But the worst case might be loss of everything in that encrypted database.

[benmayne]

I've got a single "key":<64 character string>

Nothing interesting in the logs past what I've already posted

[jasonku]

@scottnonnenberg-signal My config.json:

{
  "key": <64char string>
}

[kpuljek]

Just happened to me as well, but on beta, the database migrated days (weeks?) ago and everything worked okay. I'm on 1.15.3-beta1, updated the day it came out.

kpuljek@fsociety:~$ signal-desktop-beta 
NODE_ENV production
NODE_CONFIG_DIR /opt/Signal Beta/resources/app.asar/config
NODE_CONFIG {}
ALLOW_CONFIG_MUTATIONS undefined
HOSTNAME undefined
NODE_APP_INSTANCE undefined
SUPPRESS_NO_CONFIG_WARNING undefined
Set Windows Application User Model ID (AUMID) { appUserModelId: 'org.whispersystems.signal-desktop-beta' }
userData: /home/kpuljek/.config/Signal Beta
making app single instance
{"name":"log","hostname":"fsociety","pid":12231,"level":30,"msg":"app ready","time":"2018-08-10T16:24:51.145Z","v":0}
{"name":"log","hostname":"fsociety","pid":12231,"level":30,"msg":"Ensure attachments directory exists","time":"2018-08-10T16:24:51.149Z","v":0}
{"name":"log","hostname":"fsociety","pid":12231,"level":50,"msg":"Uncaught error or unhandled promise rejection: Error: SQLITE_NOTADB: file is not a database","time":"2018-08-10T16:24:51.154Z","v":0}

[scottnonnenberg-signal]

@kpuljek That error means that your SQLCipher decryption key, stored in ~/.config/Signal Beta/config.json is wrong somehow. Unless you have a backup of that key, your messages are lost.

You are the fourth report of this issue that we've seen, and we still don't understand why it's happening. Perhaps that config.json file was overwritten or deleted by something else, losing the key that we wrote to it? Maybe symlinks are being moved around, or things are mounted late so the file isn't available when we needed it?

I've looked at the codepath to load and save this key bit of data, and every time we write to disk we read from it immediately beforehand. If we ever try to write a value other than the key, and the previous file isn't found, we would write a file without the key. The question is: when might this happen?

[benmayne]

My computer lost power around the time of the update (I can't confirm it was actually during since I didn't notice right away) and it sounds like Jason's filled up his hard drive. Maybe we got unlucky and interrupted the migration in the middle.

[kpuljek]

Last night I was using Signal on my computer, had dinner, then turned off my PC. No updates were happening, I didn't install any new applications, I only watched local video files. Signal was running when I powered off the PC, but it almost always is. I have around 60gb of free space on my disk.

The mentioned config.json says it was last modified today when I tried to run Signal again, so something did happen. It contains a key, but I can't say if it was changed.

[scottnonnenberg-signal]

@kpuljek If you could provide your full log, that might help us track it down. It sounds like it might be some sort of interesting race condition on close of the app in your case. If you don't want to post it here, you can always send it to support@signal.org or directly to me.

[oliv3r]

as a work-around, removing the Signal profile seems to work; though that does require re-configuring the app etc etc. On linux this is .config/Signal.
I looked at the broken signal config.json and only saw one line:

{
	"key": "1234abc<redacted>123abc"
}

'file' thought that at least Database.db was an sqlite v3 database.

As for the error log in my log, it's as in the OP where it just said SQLite file is not a database.

On the new version I see 'window' is added as a new json key, but that's about it.

P.S. the json is missing an end-of-line at the end of the file after the last curly brace. Highly annoying as I was looking for the closing bracket but couldn't see it.
}username@host$
took me a moment to spot ;) Classic case of https://stackoverflow.com/questions/729692/why-should-text-files-end-with-a-newline

[scottnonnenberg-signal]

@oliv3r Usually you also see this in that file:

{
	"window": {
		"maximized": false,
		"autoHideMenuBar": false,
		"width": 1749,
		"height": 960,
		"x": 17,
		"y": 38
	}
}

Can you talk about what happened with your machine, and with your filesystem around the time of the error? Or, better, the last time Signal Desktop ran successfully before starting up with an error?

[oliv3r]

yeah, exactly that key, sorry for not writing it out, I figured the mention of the window in the new file was enough.

as for the broken file, i pasted the entire content :) so no, the window key was missing entirely, only the key key was in there.

I think the disk was full during the update, while signal was still running. What IS surprising however is that a) the json IS valid, only the window key was missing, so its not like it failed to write the file. As for other signal profile file-corruption, I don't know. I did save the profile (mv rather then rm) so I can look into things if needed.

[scottnonnenberg-signal]

@oliv3r What you're seeing if you're getting the 'not a database' error is what is written to that file on startup, not what was written when the migration happened. So the key in your config.json is a newly-generated one, not the original one that will decrypt your SQLCipher database. If your disk was full, then maybe we tried to write to disk and the file became corrupt or empty, and so we generated a new key on the next startup?

[oliv3r]

I suppose so; anyway, just wanted to report and pitch in :) the situation is resolved as freeing space and wiping the profile fixed it. ideally however the program should prevent this from happening of course

[jef-pearlman]

Just noting that this also happened to me on a Windows 10 install a couple of days ago, but I didn't have time to look into it until now. I honestly can't remember if it coincided with a version update or not. Other desktop installs on other machines remain fine.

I tried reinstalling the app (without uninstalling or wiping the profile), with no luck. I have the same messages as above in the log file. My config.json also is 4 lines with just the "key" entry. Note that when I run it, two "Signal" processes remain running indefinitely (unless I kill them)--see image at end. They generally don't use any CPU.

Let me know if there's something I can do to help track this down. If I can avoid wiping the db on this machine, it would be nice, though it will be fine if I have to do so.

Thanks!

[scottnonnenberg-signal]

@jef-pearlman Thanks for providing your experience. Your only way out of this decryption key problem is if you have a backup of that config.json file with the original decryption key in it. Otherwise you'll have to wipe the configuration and start over.

[jef-pearlman]

Got it--thanks! Is there a known cause, or anything I can do to help track it down before I reset it?

[scottnonnenberg-signal]

@jef-pearlman Before your delete the config directory, you could send us its logs subdirectory. That might help us track it down. Feel free to reach out to support@signal.org or directly to me with that.

[bob46859]

I encountered the same problem-but it was after windows 10 crashed and not during a migration. Restoring config.json from backup fixed it.

[scottnonnenberg-signal]

v1.16.x should resolve this; we've changed how we handle user configuration files.

Future readers: Please enter a new bug if you encounter this again.