Error: URI malformed - only index.txt gets updated, sync not working

tangodelta · 25 February 2020 19:55

Hello,

I’ve deployed Joplin and all seemed well. On my laptop however the sync to back-end operation stopped working.

Created remote items: 1.
Completed: 2020-02-25 20:03
Last error: Error: URI malformed

I’ve been adding web pages with the web clipper on Firefox. One of the notes didn’t appear in Joplin. This may be related.

The last note that got flushed to disk was this:

I’m having issues with finding what note is causing this.

In the debugger I’m seeing this:

But when I click “sync” those errors don’t multiply, so maybe they’re not connected to the issue.

That’s what I’m seeing in the log (.config/joplin-desktop/log.txt):

2020-02-25 19:25:58: "Starting scheduled sync"
2020-02-25 19:25:58: "Error: URI malformed
Error: URI malformed
    at EncryptionService.encrypt (/tmp/.mount_JoplinMgdiNs/resources/app/lib/services/EncryptionService.js:298:11)
    at EncryptionService.encryptAbstract_ (/tmp/.mount_JoplinMgdiNs/resources/app/lib/services/EncryptionService.js:402:33)
    at async EncryptionService.encryptString (/tmp/.mount_JoplinMgdiNs/resources/app/lib/services/EncryptionService.js:489:3)
    at async Function.serializeForSync (/tmp/.mount_JoplinMgdiNs/resources/app/lib/models/BaseItem.js:344:22)
    at async Synchronizer.start (/tmp/.mount_JoplinMgdiNs/resources/app/lib/synchronizer.js:457:25)
    at async timeoutCallback (/tmp/.mount_JoplinMgdiNs/resources/app/lib/registry.js:112:24)"
2020-02-25 19:25:58: "Operations completed: "
2020-02-25 19:25:58: "createRemote: 1"
2020-02-25 19:25:58: "Total folders: 50"
2020-02-25 19:25:58: "Total notes: 192"
2020-02-25 19:25:58: "Total resources: 934"
2020-02-25 19:25:58: "There was some errors:"
2020-02-25 19:25:58: "Error: URI malformed
Error: URI malformed
    at EncryptionService.encrypt (/tmp/.mount_JoplinMgdiNs/resources/app/lib/services/EncryptionService.js:298:11)
    at EncryptionService.encryptAbstract_ (/tmp/.mount_JoplinMgdiNs/resources/app/lib/services/EncryptionService.js:402:33)
    at async EncryptionService.encryptString (/tmp/.mount_JoplinMgdiNs/resources/app/lib/services/EncryptionService.js:489:3)
    at async Function.serializeForSync (/tmp/.mount_JoplinMgdiNs/resources/app/lib/models/BaseItem.js:344:22)
    at async Synchronizer.start (/tmp/.mount_JoplinMgdiNs/resources/app/lib/synchronizer.js:457:25)
    at async timeoutCallback (/tmp/.mount_JoplinMgdiNs/resources/app/lib/registry.js:112:24)"
2020-02-25 19:26:36: "Scheduling sync operation..."
2020-02-25 19:26:42: "Scheduling sync operation..."
2020-02-25 19:26:46: "SearchEngine: Updating FTS table..."
2020-02-25 19:26:47: "SearchEngine: Updated FTS table in 580ms. Inserted: 1. Deleted: 0"
2020-02-25 19:27:04: "Scheduling sync operation..."
2020-02-25 19:27:14: "SearchEngine: Updating FTS table..."
2020-02-25 19:27:14: "SearchEngine: Updated FTS table in 491ms. Inserted: 1. Deleted: 0"
2020-02-25 19:27:20: "RevisionService::maintenance: Starting..."

By creating a copy of the sqlite database and poking around I’ve found one thing: a binary blob (in notes.body). But then I noticed more of those and I’m confused. So, this is normal that the contents of a website are saved as a BLOB?

How can I find the specific not that’s causing this? I may just end up saving this profile on the side for debugging and build a fresh profile. How can I increase the debugging verbosity?

Thank you!

laurent · 25 February 2020 21:00

Could you create an issue about it on github please, so that it can be tracked?

tangodelta · 26 February 2020 13:24

Done

@laurent

mcarpe · 1 March 2020 21:19

Hit the same wall. I was trying to sync for the first time after having installed Joplin and imported all my Evernote notes, yesterday.

Is there any workaround for this? Or should I just sit and wait for the bug to be fixed?

laurent · 1 March 2020 23:15

Exact same bug? Could you post more info or logs @mcarpe please?

The error comes from the crypto lib we use but we haven’t changed anything to it recently so I’m surprised you would both hit the same edge case now.

mcarpe · 2 March 2020 11:21

These are the log entries:

2020-03-02 11:14:39: "Scheduling sync operation..."
2020-03-02 11:14:39: "Preparing scheduled sync"
2020-03-02 11:14:39: "Starting scheduled sync"
2020-03-02 11:14:43: "Error: URI malformed
Error: URI malformed
    at EncryptionService.encrypt (/Applications/Joplin.app/Contents/Resources/app/lib/services/EncryptionService.js:298:11)
    at EncryptionService.encryptAbstract_ (/Applications/Joplin.app/Contents/Resources/app/lib/services/EncryptionService.js:402:33)
    at processTicksAndRejections (internal/process/task_queues.js:85:5)
    at async EncryptionService.encryptString (/Applications/Joplin.app/Contents/Resources/app/lib/services/EncryptionService.js:489:3)
    at async Function.serializeForSync (/Applications/Joplin.app/Contents/Resources/app/lib/models/BaseItem.js:344:22)
    at async Synchronizer.start (/Applications/Joplin.app/Contents/Resources/app/lib/synchronizer.js:457:25)
    at async timeoutCallback (/Applications/Joplin.app/Contents/Resources/app/lib/registry.js:112:24)"
2020-03-02 11:14:43: "Operations completed: "
2020-03-02 11:14:43: "createRemote: 1"
2020-03-02 11:14:43: "Total folders: 16"
2020-03-02 11:14:43: "Total notes: 1426"
2020-03-02 11:14:43: "Total resources: 5502"
2020-03-02 11:14:43: "There was some errors:"
2020-03-02 11:14:43: "Error: URI malformed
Error: URI malformed
    at EncryptionService.encrypt (/Applications/Joplin.app/Contents/Resources/app/lib/services/EncryptionService.js:298:11)
    at EncryptionService.encryptAbstract_ (/Applications/Joplin.app/Contents/Resources/app/lib/services/EncryptionService.js:402:33)
    at processTicksAndRejections (internal/process/task_queues.js:85:5)
    at async EncryptionService.encryptString (/Applications/Joplin.app/Contents/Resources/app/lib/services/EncryptionService.js:489:3)
    at async Function.serializeForSync (/Applications/Joplin.app/Contents/Resources/app/lib/models/BaseItem.js:344:22)
    at async Synchronizer.start (/Applications/Joplin.app/Contents/Resources/app/lib/synchronizer.js:457:25)
    at async timeoutCallback (/Applications/Joplin.app/Contents/Resources/app/lib/registry.js:112:24)"

And this is the debug report for the sync operation, not sure if it’s useful.
syncReport-1583147699892.csv (1.4 KB)

I’m using the Mac desktop app and trying to sync with Dropbox (but, to be honest, this also happens when I try to sync to a local folder).

mcarpe · 3 March 2020 10:12

Hi @laurent, I’ve got a little update.

I removed the entire “Work” notebook (and sub-notebooks) and the sync suddently started without problems…

I’m not quite sure which of the notes caused the problem (seeing what @tangodelta has written it is probably one of the many >190 notes from the web clipper, most coming from Evernote, a few from the Joplin web clipper) as there were 703 notes in that notebook.

By the way: in the other notebooks I do have a lot of notes coming from the Evernote’s web clipper but none from Joplin’s. So (just a speculation) the bug is likely to come from Joplin’s web clipper…

I was just planning to install a local copy of Joplin on my work PC and keep the “Work” notes there, locally. I still would like to sync all the notes (including the Work notes) if possible, but now I’m a little scared to activate sync in my work PC as I don’t want to mess with the other notes’ syncing…

tangodelta · 3 March 2020 20:26

Hello,

I found some time to do extra testing: https://github.com/laurent22/joplin/issues/2591#issuecomment-594151046

@mcarpe : what browser are you using? What versions of software are you using (Joplin, browser, clipper etc.)?

mcarpe · 3 March 2020 21:12

(MacOS Catalina 10.15.3)
Firefox 72.0.2
Joplin 1.0.179
Joplin Web Clipper 1.0.20
Dropbox sync with E2EE

laurent · 3 March 2020 23:26

Anyone managed to find a note where this bug happens? I’m going to put the item ID in the log in the next version to make it easier to debug this problem.

tangodelta · 4 March 2020 19:48

Sadly, nope. I tried all the suspected notes with: simple, full, full HTML and screenshot clip. I didn’t try the selection clip since I have no idea what I was clipping back then.

laurent · 4 March 2020 20:22

The latest prerelease version provides more log info, which could help fix the problem. If it happens again please let me know.

@mcarpe, in your case are you still able to replicate the issue?

mcarpe · 4 March 2020 21:17

At the moment I’ve just removed the whole notebook from sync.

I’ll do some testing on the incriminated batch as soon as I got some time, hopefully in the next few days.

mcarpe · 10 March 2020 09:27

I can confirm that the problem is solved with the new version of Joplin (1.0.193).

Many thanks!