Restart & upgrade fails, then locks out client #3645

God-damnit-all · 2020-08-18T15:59:22Z

Environment

Joplin version: v1.0.234
Platform: Windows (Portable exe)
OS specifics: Windows 10 20H1

Steps to reproduce

Closed stable version of JoplinPortable.exe (and made sure Joplin was not running on my other computer just in case)
Overwrote JoplinPortable.exe with the pre-release version
Started it up from file explorer
Orange banner appears at top prompting me to restart and upgrade
Clicked the blue link to do so
Program closes, does not start back up (checked Task Manager to make sure)
Start program up, but it does not appear in the taskbar or system tray
Checked Task Manager, it's running, but all Joplin processes have 0 activity
Checked network activity, nothing is happening there either
Closed program through Task Manager, tried again, same thing

Tried this on my other computer too, this time letting Joplin idle in the background (around step 8) for 20 minutes, this didn't help, same result.

log.txt

laurent22 · 2020-08-18T16:10:00Z

Is there any error in the console? https://joplinapp.org/debugging

God-damnit-all · 2020-08-18T16:24:07Z

Is there any error in the console? https://joplinapp.org/debugging

No GUI ever loads, only background processes, i.e. no window ever appears - so I can't get to the console.

I only got an interface before I started the 'Restart & upgrade' operation (the one that's triggered by clicking the blue text in the orange banner).

God-damnit-all · 2020-08-18T22:19:21Z

Still present in 1.0.235.

laurent22 · 2020-08-18T23:14:56Z

No GUI ever loads, only background processes, i.e. no window ever appears - so I can't get to the console.

Isn't it because the window is somewhere off-screen? What if you try this technique: https://www.howtogeek.com/howto/windows/bring-misplaced-off-screen-windows-back-to-your-desktop-keyboard-trick/

Also to be completely sure, could you maybe try to restart your computer, then start the app again? (just in case there's some process stuck in memory)

God-damnit-all · 2020-08-18T23:26:29Z

No GUI ever loads, only background processes, i.e. no window ever appears - so I can't get to the console.

Isn't it because the window is somewhere off-screen? What if you try this technique: https://www.howtogeek.com/howto/windows/bring-misplaced-off-screen-windows-back-to-your-desktop-keyboard-trick/

Also to be completely sure, could you maybe try to restart your computer, then start the app again? (just in case there's some process stuck in memory)

I did this on two separate computers, and I have it configured to use the systray icon. No systray icon appears, including when you press on Show hidden icons.

laurent22 · 2020-08-19T06:11:51Z

How many notes do you have? This new release needs to migrate the search engine index on startup and it can be very slow if you have many notes. What if you let it run all day to be sure?

God-damnit-all · 2020-08-19T15:01:59Z

I used Process Hacker to check and see if any of the Joplin processes were doing anything whatsoever. It's just idle, doing nothing. I'll let it run all day, sure.

God-damnit-all · 2020-08-20T03:28:17Z

Okay, it ran all day. No change.

laurent22 · 2020-08-20T09:03:34Z

Hmm, that's not good. I've made a fix to the portable app but I don't think it would change something in your case. Could you stop the process completely (in task manager), then delete the log file, and run the app again? Then if you could upload the log file here so that I can see where it's stopping. Make sure to enable the debugging flags as described there: https://joplinapp.org/debugging/#desktop-application

laurent22 · 2020-08-20T09:07:06Z

But I'm still surprised the window doesn't show up at all. If you press Windows Key + Tab does something show up for Joplin?

God-damnit-all · 2020-08-20T16:38:18Z

But I'm still surprised the window doesn't show up at all. If you press Windows Key + Tab does something show up for Joplin?

Hmm, that's not good. I've made a fix to the portable app but I don't think it would change something in your case. Could you stop the process completely (in task manager), then delete the log file, and run the app again? Then if you could upload the log file here so that I can see where it's stopping. Make sure to enable the debugging flags as described there: https://joplinapp.org/debugging/#desktop-application

I'm assuming flags.txt goes in the JoplinProfile folder for the portable version? Went ahead and did that, here's the logs: log.zip

laurent22 · 2020-08-20T21:21:05Z

I can't see anything abnormal in the log, and there's no error, so I'm not sure what's causing this.

What if you reinstall the portable app on a different USB drive, then open the app from a different computer? I'm thinking maybe there's some corrupted state on a temp file somewhere which prevents the app from starting. So if you try from a different computer it might help.

gerroon · 2020-08-21T00:13:15Z

I have the same issue on Debian Linux .appimage

I only have is this and no Joplin on the desktop or on the tray. This obviously happened after letting it try that upgrade thing. It is running because I can see it in the ps aux but that is pretty much it.

I would be happy to provide logs if you can tell me how to generate it.

./joplin.app 
(electron) The default value of app.allowRendererProcessReuse is deprecated, it is currently "false".  It will change to be "true" in Electron 9.  For more information please check https://github.com/electron/electron/issues/18397

God-damnit-all · 2020-08-21T05:12:17Z

I can't see anything abnormal in the log, and there's no error, so I'm not sure what's causing this.

What if you reinstall the portable app on a different USB drive, then open the app from a different computer? I'm thinking maybe there's some corrupted state on a temp file somewhere which prevents the app from starting. So if you try from a different computer it might help.

I already did this on two separate computers and I wasn't using a pen drive on either of them - I simply prefer portable versions of software when they're available because they make OS reinstalls much less painful when they have to happen. Both of them started initially on the new version, and then refused to open after the Restart & upgrade process was clicked on.

ashemsay · 2020-08-21T09:06:33Z

Hello, I can confirm had the same issue with the AppImage on my Ubuntu. I somehow managed to get it started by killing and launching again several times but it looks like it fucked something up, now my windows client can't sync anymore, saying my client must be upgraded even if I have the latest version installed.
Just for info I use nextcloud sync.

laurent22 · 2020-08-21T14:09:20Z

I think it has something to do with Electron restart mechanism, but in way I don't understand. At worst it should fail, and then you can start the app manually, but it seems to be keeping some state around that breaks the app afterwards.

laurent22 · 2020-08-21T14:13:47Z

Could you check using an SQLite database browser, what's the value of "sync.upgradeState" in the "settings" table?

God-damnit-all · 2020-08-21T14:53:19Z

Could you check using an SQLite database browser, what's the value of "sync.upgradeState" in the "settings" table?

2

God-damnit-all · 2020-08-21T15:00:24Z

After changing the value to 0, the app successfully starts up again, but if I try to synchronize, it will give me the orange banner and want to try to upgrade again.

So I think what's happening is that it's being put in the upgrade state but the upgrade just never starts. Maybe it has something to do with using a WebDAV server as my sync target, I don't know.

God-damnit-all · 2020-08-21T15:01:56Z

Oh, here's a probable cause:

This WebDAV target works completely fine in the stable version, why doesn't it work here? It even succeeds when you press the 'Check synchronization configuration' button.

At least I'm able to use Joplin again, with sync disabled for now.

gerroon · 2020-08-21T17:50:32Z

I can confirm that setting this back to 0 lets me use Joplin again, with that bothering orange banner up there which I wont click on it for a while.

sync.upgradeState=0

laurent22 · 2020-08-21T22:18:24Z

Ok thanks for checking so it seems to be something strange that Electron is doing when restarting the app. I'll see if I can replicate it but it will have to wait for at least a week. If you're stuck, you can always export your notes then delete everything and go back to an earlier version.

afv · 2020-08-27T10:54:50Z

Hello,
I'm having the exact same problem, on Arch Linux, using the AppImage package.
I did not update the package for some time as it changed the name (from joplin-appimg to joplin-appimage) and I didn't notice.

[2020-08-26T23:45:38+0100] [ALPM] removed joplin-appimg (1.0.218-0)
[2020-08-26T23:53:34+0100] [ALPM] installed joplin-appimage (1.0.235-1)

Yesterday I read all the change logs since the version I had, did the upgrade and clicked the banner to restart to upgrade the sync target. Joplin closed and did not open again by itself, so I opened it (after some time waiting) and nothing happened, as reported.

All I have in the logs is:

2020-08-27 11:46:52: "Profile directory: /home/afv/.config/joplin-desktop"
2020-08-27 11:46:52: "KeychainService: checking if keychain supported"
2020-08-27 11:46:52: "KeychainService: check was already done - skipping. Supported:", "0"
2020-08-27 11:46:52: "Client ID: 99c831248b2944b6a8fdfcce6af86be4"
2020-08-27 11:46:52: "Trying to load 2 master keys..."
2020-08-27 11:46:52: "Loaded master keys: 2"
2020-08-27 11:46:52: "ResourceFetcher: Auto-add resources: Mode: always"
2020-08-27 11:46:52: "ResourceFetcher: Auto-added resources: 0"
2020-08-27 11:47:02: "SearchEngine: Updating FTS table..."
2020-08-27 11:47:03: "SearchEngine: Updated FTS table in 11ms. Inserted: 0. Deleted: 0"

2020-08-27 11:46:52: "Database was open successfully"
2020-08-27 11:46:52: "Checking for database schema update..."
2020-08-27 11:46:52: "Current database version", "33"
2020-08-27 11:46:52: "UPDATE resource_local_states SET fetch_status = ? WHERE fetch_status = ?"
2020-08-27 11:46:52: "[0,1]"
2020-08-27 11:46:52: "
			SELECT count(*) as total
			FROM resource_local_states
			WHERE fetch_status = ?
		"
2020-08-27 11:46:52: "[3]"
2020-08-27 11:47:03: "
					SELECT id, item_id, type
					FROM item_changes
					WHERE item_type = ?
					AND id > ?
					ORDER BY id ASC
					LIMIT 10
				"
2020-08-27 11:47:03: "[1,7549]"
2020-08-27 11:47:03: "DELETE FROM item_changes WHERE id <= ?"
2020-08-27 11:47:03: "[7517]"

Changing sync.upgradeState from 2 to 0 "fixed" it (it opens), but we are unable to sync the notes, right?

Thanks.

God-damnit-all · 2020-08-28T14:19:28Z

@laurent22 This is still an issue in v1.0.236

thwaller · 2020-08-29T08:40:58Z

I have the same issue on 1.0.236, on Ubuntu 18.04.5. I am syncing to OneDrive. I changed the upgrade value to 0 in the DB and Joplin again opens. Does this mean I cannot sync until this is fixed?

This is a bit concerning, only because I question the integrity of my notes of which I have a lot. How to proceed?

laurent22 · 2020-08-29T10:27:58Z

For the record this is caused by this bug in electron-builder: electron-userland/electron-builder#4650

laurent22 · 2020-08-29T15:38:31Z

If you're having a problem with the AppImage, please could you try this release and let me know if it works?

https://github.com/laurent22/joplin/releases/tag/v1.0.237

God-damnit-all · 2020-08-29T16:19:15Z

I'm using the Windows portable, and for me this issue is still ongoing in v1.0.237.

thwaller · 2020-08-29T16:25:25Z

Using the new version, I see it did ask me to restart the program in a popup. I did this and nothing is changed. It still was stuck on the status 2 requiring me to change to 0.

afv · 2020-08-29T16:41:39Z

Same on Arch Linux.

$ /opt/appimages/Joplin.AppImage
(electron) The default value of app.allowRendererProcessReuse is deprecated, it is currently "false".  It will change to be "true" in Electron 9.  For more information please check https://github.com/electron/electron/issues/18397

Joplin for Desktop

Copyright © 2016-2020 Laurent Cozic
Joplin 1.0.237 (prod, linux)

Client ID: d192515ad79246b3b68a0eec66296ee4
Sync Version: 2
Profile Version: 33
Keychain Supported: No

Revision: 797f4a9 (master)

log.txt

2020-08-29 17:33:07: "Profile directory: /home/afv/.config/joplin-desktop"
2020-08-29 17:33:07: "KeychainService: checking if keychain supported"
2020-08-29 17:33:07: "KeychainService: check was already done - skipping. Supported:", "0"
2020-08-29 17:33:07: "Client ID: d192515ad79246b3b68a0eec66296ee4"
2020-08-29 17:33:07: "Trying to load 2 master keys..."
2020-08-29 17:33:07: "Loaded master keys: 2"
2020-08-29 17:33:07: "ResourceFetcher: Auto-add resources: Mode: always"
2020-08-29 17:33:07: "ResourceFetcher: Auto-added resources: 0"
2020-08-29 17:33:17: "SearchEngine: Updating FTS table..."
2020-08-29 17:33:18: "SearchEngine: Updated FTS table in 1ms. Inserted: 0. Deleted: 0"

log-database.txt

2020-08-29 17:32:42: "Saving settings..."
2020-08-29 17:32:42: "Settings have been saved."

2020-08-29 17:33:07: "Database was open successfully"
2020-08-29 17:33:07: "Checking for database schema update..."
2020-08-29 17:33:07: "Current database version", "33"

After reverting sync.upgradeState to 0:

log.txt

2020-08-29 17:38:51: "Profile directory: /home/afv/.config/joplin-desktop"
2020-08-29 17:38:51: "KeychainService: checking if keychain supported"
2020-08-29 17:38:51: "KeychainService: check was already done - skipping. Supported:", "0"
2020-08-29 17:38:51: "Client ID: d192515ad79246b3b68a0eec66296ee4"
2020-08-29 17:38:51: "Trying to load 2 master keys..."
2020-08-29 17:38:51: "Loaded master keys: 2"
2020-08-29 17:38:51: "ResourceFetcher: Auto-add resources: Mode: always"
2020-08-29 17:38:51: "ResourceFetcher: Auto-added resources: 0"
2020-08-29 17:38:51: "Trying to load 2 master keys..."
2020-08-29 17:38:51: "Loaded master keys: 2"
2020-08-29 17:38:51: "Trying to load 2 master keys..."
2020-08-29 17:38:51: "Loaded master keys: 2"
2020-08-29 17:38:51: "Trying to load 2 master keys..."
2020-08-29 17:38:51: "Loaded master keys: 2"
2020-08-29 17:38:51: "RevisionService::runInBackground: Starting background service with revision collection interval 600000"
2020-08-29 17:38:52: "DecryptionWorker: starting decryption..."
2020-08-29 17:38:52: "DecryptionWorker: completed decryption."
2020-08-29 17:38:55: "RevisionService::maintenance: Starting..."
2020-08-29 17:38:55: "RevisionService::maintenance: Service is enabled"
2020-08-29 17:38:56: "RevisionService::collectRevisions: Created revisions for 1 notes"
2020-08-29 17:38:56: "RevisionService::maintenance: Done in 231ms"
2020-08-29 17:39:01: "SearchEngine: Updating FTS table..."
2020-08-29 17:39:01: "Preparing scheduled sync"
2020-08-29 17:39:01: "Starting scheduled sync"
2020-08-29 17:39:01: "Sync version of the target (1) is lower than the version supported by the client (2). Please upgrade the sync target."
2020-08-29 17:39:01: "Operations completed: "
2020-08-29 17:39:01: "SearchEngine: Updated FTS table in 2ms. Inserted: 0. Deleted: 0"
2020-08-29 17:39:01: "Total folders: 33"
2020-08-29 17:39:01: "Total notes: 456"
2020-08-29 17:39:01: "Total resources: 911"
2020-08-29 17:39:01: "Updating all notifications..."
2020-08-29 17:39:01: "Garbage collecting alarms..."
2020-08-29 17:39:02: "DecryptionWorker: starting decryption..."
2020-08-29 17:39:02: "DecryptionWorker: completed decryption."
2020-08-29 17:39:21: "ResourceService::indexNoteResources: Start"
2020-08-29 17:39:23: "ResourceService::indexNoteResources: Completed"
2020-08-29 17:39:23: "ResourceService::deleteOrphanResources:", "[]"

log-database.txt

2020-08-29 17:38:51: "Database was open successfully"
2020-08-29 17:38:51: "Checking for database schema update..."
2020-08-29 17:38:51: "Current database version", "33"
2020-08-29 17:38:52: "Saving settings..."
2020-08-29 17:38:53: "Settings have been saved."
2020-08-29 17:38:55: "Saving settings..."
2020-08-29 17:38:56: "Settings have been saved."
2020-08-29 17:39:02: "Saving settings..."
2020-08-29 17:39:02: "Settings have been saved."
2020-08-29 17:39:23: "Saving settings..."
2020-08-29 17:39:23: "Settings have been saved."

laurent22 · 2020-08-29T19:34:05Z

Ok it seems it's not even starting the migration process, but I don't get at what point it's getting stuck. I'm going to add more log entries to find out.

gerroon · 2020-08-30T01:44:44Z

I originally reported this for .appimage on Debian but i am able to repeat this on Windows x64 UThe upgrade fails and it never restarts

laurent22 · 2020-09-01T21:33:43Z

If you're having this issue, please try release 239: https://github.com/laurent22/joplin/releases/tag/v1.0.239

With this release, it should show you whatever is preventing the upgrade to happen - it might be something you can fix, like invalid username or password, or some application error. Either way please give it a try and let me know if you're able to proceed with the upgrade.

afv · 2020-09-01T22:08:21Z

Now a white window appeared saying Joplin is upgrading and might take some minutes; after some time a pop up window appeared, to restart Joplin, and everything seems to be working now. 😃

Logs:

2020-09-01 23:03:22: "Profile directory: /home/afv/.config/joplin-desktop"
2020-09-01 23:03:22: "KeychainService: checking if keychain supported"
2020-09-01 23:03:22: "KeychainService: check was already done - skipping. Supported:", "0"
2020-09-01 23:03:22: "Client ID: d192515ad79246b3b68a0eec66296ee4"
2020-09-01 23:03:22: "Trying to load 2 master keys..."
2020-09-01 23:03:22: "Loaded master keys: 2"
2020-09-01 23:03:22: "ResourceFetcher: Auto-add resources: Mode: always"
2020-09-01 23:03:22: "ResourceFetcher: Auto-added resources: 0"
2020-09-01 23:03:22: "app.start: doing upgradeSyncTarget action"
2020-09-01 23:03:22: "useSyncTargetUpgrade: Starting process..."
2020-09-01 23:03:22: "useSyncTargetUpgrade: Acquire synchronizer..."
2020-09-01 23:03:22: "useSyncTargetUpgrade: Create migration handler..."
2020-09-01 23:03:22: "useSyncTargetUpgrade: Start upgrade..."
2020-09-01 23:03:22: "MigrationHandler: Sync target version is 0 or 1 - creating "locks" directory:", "{"version":1}"
2020-09-01 23:03:22: "MigrationHandler: Acquiring exclusive lock"
2020-09-01 23:03:22: "MigrationHandler: Acquired exclusive lock:", "{"type":"exclusive","clientType":"desktop","clientId":"d192515ad79246b3b68a0eec66296ee4","updatedTime":1598997802424}"
2020-09-01 23:03:22: "MigrationHandler: Migrating from version 1 to version 2"
2020-09-01 23:03:22: "MigrationHandler: Done migrating from version 1 to version 2"
2020-09-01 23:03:22: "MigrationHandler: Releasing exclusive lock"
2020-09-01 23:03:22: "useSyncTargetUpgrade: Error:", "null"

God-damnit-all · 2020-09-01T22:47:01Z

It works! Hallelujah!

thwaller · 2020-09-01T22:57:43Z

I did get this to work, however, I needed to start it via command line. When starting from menu, it would lock up a screen and become unresponsive. Quite strange. Regardless, it did end up working.

laurent22 · 2020-09-02T09:53:37Z

Brilliant, thanks guys for confirming that it works.

gerroon · 2020-09-02T15:18:04Z

The appimage on Debian worked but autorestarts still failed. It worked after manual restarts.

God-damnit-all added the bug It's a bug label Aug 18, 2020

God-damnit-all changed the title ~~Restart & upgrade sync fails, then locks out client~~ Restart & upgrade fails, then locks out client Aug 18, 2020

laurent22 added desktop All desktop platforms high High priority issues labels Aug 18, 2020

laurent22 closed this as completed in 815775a Aug 29, 2020

laurent22 reopened this Aug 29, 2020

laurent22 closed this as completed in bdfb6b9 Sep 1, 2020

laurent22 reopened this Sep 1, 2020

God-damnit-all closed this as completed Sep 1, 2020

Restart & upgrade fails, then locks out client #3645

Restart & upgrade fails, then locks out client #3645

Comments

God-damnit-all commented Aug 18, 2020

Environment

Steps to reproduce

laurent22 commented Aug 18, 2020

God-damnit-all commented Aug 18, 2020 • edited Loading

God-damnit-all commented Aug 18, 2020

laurent22 commented Aug 18, 2020

God-damnit-all commented Aug 18, 2020

laurent22 commented Aug 19, 2020

God-damnit-all commented Aug 19, 2020

God-damnit-all commented Aug 20, 2020

laurent22 commented Aug 20, 2020

laurent22 commented Aug 20, 2020

God-damnit-all commented Aug 20, 2020

laurent22 commented Aug 20, 2020

gerroon commented Aug 21, 2020 • edited Loading

God-damnit-all commented Aug 21, 2020 • edited Loading

ashemsay commented Aug 21, 2020

laurent22 commented Aug 21, 2020

laurent22 commented Aug 21, 2020

God-damnit-all commented Aug 21, 2020

God-damnit-all commented Aug 21, 2020

God-damnit-all commented Aug 21, 2020 • edited Loading

gerroon commented Aug 21, 2020 • edited Loading

laurent22 commented Aug 21, 2020

afv commented Aug 27, 2020

God-damnit-all commented Aug 28, 2020

thwaller commented Aug 29, 2020 • edited Loading

laurent22 commented Aug 29, 2020

laurent22 commented Aug 29, 2020

God-damnit-all commented Aug 29, 2020

thwaller commented Aug 29, 2020

afv commented Aug 29, 2020

laurent22 commented Aug 29, 2020

gerroon commented Aug 30, 2020

laurent22 commented Sep 1, 2020

afv commented Sep 1, 2020 • edited Loading

God-damnit-all commented Sep 1, 2020

thwaller commented Sep 1, 2020

laurent22 commented Sep 2, 2020

gerroon commented Sep 2, 2020

God-damnit-all commented Aug 18, 2020 •

edited

Loading

gerroon commented Aug 21, 2020 •

edited

Loading

God-damnit-all commented Aug 21, 2020 •

edited

Loading

God-damnit-all commented Aug 21, 2020 •

edited

Loading

gerroon commented Aug 21, 2020 •

edited

Loading

thwaller commented Aug 29, 2020 •

edited

Loading

afv commented Sep 1, 2020 •

edited

Loading