Hi all, I've just installed Joplin Server 2.0 using Docker and everything seemed to be fine with the install. I have created a new user, and started the initial sync using the "Re-upload local data to sync target" option,, but after about a thousand items I get:
Created remote items: 1214.
Completed: 20/05/2021 22:46
Last error: Error: Unknown error
Client version is 2.0.1 on linux.
Last few lines of the log are:
joplin_app | 2021-05-20 20:46:19: App: PUT /api/items/root:/10e5db7d77bd40ebac7a5079c6d7a626.md:/content
joplin_app | 2021-05-20 20:46:20: App: GET /api/items/root:/eb4e7a49b94d46d89568e0dee1b87862.md:
joplin_app | 2021-05-20 20:46:20: [error] App: 404: GET /api/items/root:/eb4e7a49b94d46d89568e0dee1b87862.md: : Not found: root:/eb4e7a49b94d46d89568e0dee1b87862.md:
joplin_app | 2021-05-20 20:46:20: App: PUT /api/items/root:/eb4e7a49b94d46d89568e0dee1b87862.md:/content
joplin_app | 2021-05-20 20:46:20: App: GET /api/items/root:/dada987ba9cd476b953e0496bbd6faed.md:
joplin_app | 2021-05-20 20:46:20: [error] App: 404: GET /api/items/root:/dada987ba9cd476b953e0496bbd6faed.md: : Not found: root:/dada987ba9cd476b953e0496bbd6faed.md:
joplin_app | 2021-05-20 20:46:21: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 20:46:21: ShareService: Starting maintenance...
joplin_app | 2021-05-20 20:46:21: ShareService: Maintenance completed in 20ms
joplin_app | 2021-05-20 20:46:21: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 20:46:21: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 20:46:21: App: PUT /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:/content
joplin_app | 2021-05-20 20:46:43: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 20:46:44: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 20:46:44: App: DELETE /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:
joplin_app | 2021-05-20 20:46:44: App: GET /api/share_users
joplin_app | 2021-05-20 20:46:45: App: GET /api/shares
db_1 | 2021-05-20 20:49:56.812 UTC [143] FATAL: password authentication failed for user "postgres"
db_1 | 2021-05-20 20:49:56.812 UTC [143] DETAIL: Role "postgres" does not exist.
db_1 | Connection matched pg_hba.conf line 99: "host all all all md5"
If I log into the web page of the sync server, I get a red box with a dbase error:
select "items"."id", "items"."name", "items"."updated_time", count(*) from "user_items" left join "items" on "user_items"."item_id" = "items"."id" where "user_items"."user_id" = $1 - column "items.id" must appear in the GROUP BY clause or be used in an aggregate function
The "log" menu item shows about 100 entries (markdown files) and if I click on one I indeed get the note json.
Anyone have any ideas?
Thanks!
Mark
The red box is normal and the fix will be in the next release. But it's strange that you got a db auth error in the middle of a sync. Does it still show that error if you try to sync again?
Thanks @laurent - yes, subsequent syncs also fail. The logs when trying to create the first item. The log for two subsequent sync attempts:
joplin_app | 2021-05-20 21:02:41: App: GET /api/items/root:/info.json:/content
joplin_app | 2021-05-20 21:02:42: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:02:42: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:02:42: App: PUT /api/items/root:/temp/timeCheck665257.txt:/content
joplin_app | 2021-05-20 21:02:43: App: GET /api/items/root:/temp/timeCheck665257.txt:
joplin_app | 2021-05-20 21:02:43: App: PUT /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:/content
joplin_app | 2021-05-20 21:02:43: App: DELETE /api/items/root:/temp/timeCheck665257.txt:
joplin_app | 2021-05-20 21:02:43: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:02:43: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:02:44: App: GET /api/items/root:/dada987ba9cd476b953e0496bbd6faed.md:
joplin_app | 2021-05-20 21:02:44: [error] App: 404: GET /api/items/root:/dada987ba9cd476b953e0496bbd6faed.md: : Not found: root:/dada987ba9cd476b953e0496bbd6faed.md:
joplin_app | 2021-05-20 21:03:07: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:03:08: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:03:08: App: DELETE /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:
joplin_app | 2021-05-20 21:03:08: App: GET /api/share_users
joplin_app | 2021-05-20 21:03:08: App: GET /api/shares
joplin_app | 2021-05-20 21:05:08: App: GET /api/items/root:/info.json:/content
joplin_app | 2021-05-20 21:05:08: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:05:08: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:05:09: App: PUT /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:/content
joplin_app | 2021-05-20 21:05:09: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:05:09: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:05:10: App: GET /api/items/root:/dada987ba9cd476b953e0496bbd6faed.md:
joplin_app | 2021-05-20 21:05:10: [error] App: 404: GET /api/items/root:/dada987ba9cd476b953e0496bbd6faed.md: : Not found: root:/dada987ba9cd476b953e0496bbd6faed.md:
joplin_app | 2021-05-20 21:05:33: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:05:33: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-20 21:05:33: App: DELETE /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:
joplin_app | 2021-05-20 21:05:34: App: GET /api/share_users
joplin_app | 2021-05-20 21:05:34: App: GET /api/shares
A bit hard to tell from the server log, because the 404 errors could be normal if it's just the app checking if the file exists. What does the app log says?
The client log shows one error:
/tmp/.mount_JoplinyWMkpA/resources/app.asar/node_modules/@joplin/lib/Logger.js:188 23:13:25: Error: Unknown error
at newError (/tmp/.mount_JoplinyWMkpA/resources/app.asar/node_modules/@joplin/lib/JoplinServerApi.js:151)
at JoplinServerApi.<anonymous> (/tmp/.mount_JoplinyWMkpA/resources/app.asar/node_modules/@joplin/lib/JoplinServerApi.js:177)
at Generator.throw (<anonymous>)
at rejected (/tmp/.mount_JoplinyWMkpA/resources/app.asar/node_modules/@joplin/lib/JoplinServerApi.js:6)
Hmm that's not helping much unfortunately. I thought I had it setup to give detailed errors but looks like not.
So if there's only one error in total in the log does it mean the sync operation complete successfully now? Or do you mean there's always one error when you try to sync?
In the dev version, it's possible to display all detailed requests and responses in the console so I think I'll add this in the next version to help us debug such issues.
Correct there is one error in the log, and the sync stops at that point (and the whole thing repeats of course at the next auto-sync interval). Let me know if I can provide any more info, otherwise I'll wait until the next version with more debugging info, and sync back to dropbox!
The latest version 2.0.2 should now print a warning in the console with detailed info when there's an error. Could you give it a try? https://joplinapp.org/debugging It would print a curl command, which can even manually try in a terminal to easily replicate the bug and possibly get more info that way.
Hi @laurent - actually, 2.0.2 seems to be syncing OK right now, so I'll let it run and let you know the outcome!
The only thing that puzzles me is that I can see that items are syncing, but the "log" option in the server (i.e. /changes) only shows a handful of items from my first sync, nothing more. Is this expected?
This page had a bug in the current version of Joplin Server, which would make it display less items that there is, but it should be fixed in the next version.
Aha, great, then I won't rely on that, but check the sync status when it's complete. Thanks!
HI @laurent the sync worked OK, but it seemed to fail on some (all?) of my attachments I got the message "Some items cannot be synchronised. [View them now]"
When I go to the sync status and click on "retry" the sync for those items works fine.
Edit: actually, that's not true, they just look like they're syncing, but end up at the bottom of the list again...
Could you check what this unknown error is? Either on server logs or console in dev mode?
Find attached the client log from an attempt to sync one of the attachments:
The last part of the server log is:
joplin_app | 2021-05-23 16:25:40: App: GET /home
joplin_app | 2021-05-23 16:25:40: App: GET /css/bulma.min.css
joplin_app | 2021-05-23 16:25:40: App: GET /css/bulma-prefers-dark.min.css
joplin_app | 2021-05-23 16:25:40: App: GET /css/main.css
joplin_app | 2021-05-23 16:25:40: App: GET /js/main.js
joplin_app | 2021-05-23 16:25:40: App: GET /css/fontawesome/css/all.min.css
joplin_app | 2021-05-23 16:25:42: App: GET /images/Logo.png
joplin_app | 2021-05-23 16:25:42: App: GET /favicon.ico
joplin_app | 2021-05-23 16:25:42: [error] App: 404: GET /favicon.ico : Path not found: favicon.ico
joplin_app | 2021-05-23 16:27:28: App: GET /api/items/root:/info.json:/content
joplin_app | 2021-05-23 16:27:28: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:27:28: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:27:28: App: PUT /api/items/root:/temp/timeCheck74057.txt:/content
joplin_app | 2021-05-23 16:27:29: App: GET /api/items/root:/temp/timeCheck74057.txt:
joplin_app | 2021-05-23 16:27:29: App: DELETE /api/items/root:/temp/timeCheck74057.txt:
joplin_app | 2021-05-23 16:27:29: App: PUT /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:/content
joplin_app | 2021-05-23 16:27:29: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:27:29: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:27:30: App: GET /api/items/root:/:/delta
joplin_app | 2021-05-23 16:27:31: App: DELETE /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:
joplin_app | 2021-05-23 16:27:31: App: GET /api/share_users
joplin_app | 2021-05-23 16:27:31: App: GET /api/shares
joplin_app | 2021-05-23 16:32:33: App: GET /api/items/root:/info.json:/content
joplin_app | 2021-05-23 16:32:33: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:32:33: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:32:34: App: PUT /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:/content
joplin_app | 2021-05-23 16:32:34: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:32:34: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:32:35: App: GET /api/items/root:/:/delta
joplin_app | 2021-05-23 16:32:36: App: DELETE /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:
joplin_app | 2021-05-23 16:32:36: App: GET /api/share_users
joplin_app | 2021-05-23 16:32:36: App: GET /api/shares
joplin_app | 2021-05-23 16:34:29: App: GET /api/items/root:/info.json:/content
joplin_app | 2021-05-23 16:34:29: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:34:30: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:34:30: App: PUT /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:/content
joplin_app | 2021-05-23 16:34:30: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:34:30: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:34:31: App: GET /api/items/root:/90025dbddaa7e5d435b46bb1a6f0e7ba.md:
joplin_app | 2021-05-23 16:34:31: [error] App: 404: GET /api/items/root:/90025dbddaa7e5d435b46bb1a6f0e7ba.md: : Not found: root:/90025dbddaa7e5d435b46bb1a6f0e7ba.md:
joplin_app | 2021-05-23 16:34:32: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:34:32: App: GET /api/items/root:/locks/*:/children
joplin_app | 2021-05-23 16:34:33: App: GET /api/items/root:/:/delta
joplin_app | 2021-05-23 16:34:34: App: DELETE /api/items/root:/locks/sync_desktop_427feb3bb84541ebb73910a937fd9c40.json:
joplin_app | 2021-05-23 16:34:34: App: GET /api/share_users
joplin_app | 2021-05-23 16:34:34: App: GET /api/shares
Nothing is jumping out at me here, but shout if you see something else I should check/try!
Thanks, Mark
The part I don't get is that the call that fails is a PUT call, however there's no such request on the server (it should have been visible just after the error at "2021-05-23 16:34:31")
So I'm wondering, is it possible that something is blocking certain requests before it reaches the server? Maybe some proxy or firewall?
I'm using a reverse proxy with nginx, but nothing that I can see would selectively block requests. Is there something special about the way resources are handled that I could dig into?
Nothing special I can think of. Could you maybe check the nginx log to see if it's seeing that PUT request and forwarding it to Joplin Server correctly? Because it seems Joplin Server is not seeing those requests at all at the moment. Maybe something to do with a max request size on Nginx size?
1 Like
Ahh, I think you're onto a winner here - don't know why I didn't think of that! Indeed I see errors like client intended to send too large body in the nginx logs; I'll try to increase the max size and try again...
1 Like
Yep, that fixed it - thanks @laurent - I bumped up client_max_body_size in the nginx config and now the attachments sync.
Is there any way to "retry all" from the sync status page? There are many hundres of items, and it would take me quite a while to click "retry" on each one? 
Otherwise I can start the sync again, but that will also take a while...
Thanks for your help!
1 Like
No, I thought a Retry All button was created for these items but looks like it isn't, so unfortunately your only options are either to manually click, or start over from the beginning. I'll add the button in a future version.
