Joplin Server not Responding (2.6.12)

[neurokrish]

Has anyone had issues with the latest update? My Joplin server got updated and it is in a not-responding state. I restored the app to a previous backup and everything was fine. However, the app got updated again today (due to automatic updates) and it is stuck as not-responding again. Also, is there a way to stop updates / app rather than globally?

[luckow]

no. yes
This is also possible at app level.

[neurokrish]

@luckow thanks. So, I am not sure what's happening on my instance then. I will roll back the current update, and update to the next version whenever it becomes available. Oh, I saw that automatic update thing in the app, should have probed further. I thought it disables updates for all apps.

[girish]

@neurokrish to debug, what you can do is to clone the app with the latest backup and then update it to latest. If you can post the logs, it will give an idea of why it's not starting.

I have a hunch this is related to "clock skew" . The newer joplin seems to be fairly aggressive with some clock skew check and won't start up. Can you please try this: Add the like below in /app/data/config (which you can edit using the File manager )

MAX_TIME_DRIFT=100

I added the above by default in new installation but maybe older installations need that too.

[ei8fdb]

@girish said in Joplin Server not Responding (2.6.12):

I have a hunch this is related to "clock skew" . The newer joplin seems to be fairly aggressive with some clock skew check and won't start up.

Working version: v1.2.5
Failing version: v1.2.6

@girish You're right - when I stop and restart my Joplin app server I'm seeing clock skew errors in the logs:

Nov 26 09:51:49 box:settings initCache: pre-load settings
Nov 26 09:51:49 box:taskworker Starting task 4377. Logs are at /home/yellowtent/platformdata/logs/7962ae53-502c-4c68-b1eb-580da056615c/apptask.log
Nov 26 09:51:49 box:apptask run: startTask installationState: pending_restart runState: running
Nov 26 09:51:49 box:tasks update 4377: {"percent":20,"message":"Restarting container"}
Nov 26 09:51:49 box:tasks update 4377: {"percent":100,"message":"Done"}
Nov 26 09:51:49 ==> starting server
Nov 26 09:51:49 box:taskworker Task took 0.363 seconds
Nov 26 09:51:49 box:tasks setCompleted - 4377: {"result":null,"error":null}
Nov 26 09:51:49 box:tasks update 4377: {"percent":100,"result":null,"error":null}
Nov 26 09:51:49
Nov 26 09:51:49 > @joplin/server@2.6.12 start
Nov 26 09:51:49 > node dist/app.js
Nov 26 09:51:49
Nov 26 09:51:51 2021-11-26 08:51:51: App: Starting server v2.6.12 (prod) on port 3000 and PID 30...
****
Nov 26 09:51:51 Error: The device time drift is 581488ms (Max allowed: 10ms) - cannot continue as it could cause data loss and conflicts on the sync clients. You may increase env var MAX_TIME_DRIFT to pass the check.**
****
Nov 26 09:51:51 at /app/code/packages/server/src/app.ts:256:10
Nov 26 09:51:51 at Generator.next (<anonymous>)
Nov 26 09:51:51 at fulfilled (/app/code/packages/server/dist/app.js:5:58)
Nov 26 09:51:51 at processTicksAndRejections (node:internal/process/task_queues:96:5)
Nov 26 09:51:51 ==> starting server
Nov 26 09:51:52
Nov 26 09:51:52 > @joplin/server@2.6.12 start
Nov 26 09:51:52 > node dist/app.js
Nov 26 09:51:52
Nov 26 09:51:53 2021-11-26 08:51:53: App: Starting server v2.6.12 (prod) on port 3000 and PID 30...
****
Nov 26 09:51:53 Error: The device time drift is 581488ms (Max allowed: 10ms) - cannot continue as it could cause data loss and conflicts on the sync clients. You may increase env var MAX_TIME_DRIFT to pass the check.
****
Nov 26 09:51:53 at /app/code/packages/server/src/app.ts:256:10

I'll try your suggestion with the max time drift parameter and report back later.

[ei8fdb]

@girish said in Joplin Server not Responding (2.6.12):

Can you please try this: Add the like below in /app/data/config (which you can edit using the File manager )
MAX_TIME_DRIFT=100

I added that line to the config file, restarted, then upgraded and can confirm it's still not starting:

Nov 26 10:07:58 box:settings initCache: pre-load settings
Nov 26 10:07:58 box:taskworker Starting task 4382. Logs are at /home/yellowtent/platformdata/logs/7962ae53-502c-4c68-b1eb-580da056615c/apptask.log
Nov 26 10:07:58 box:apptask run: startTask installationState: pending_start runState: running
Nov 26 10:07:58 box:tasks update 4382: {"percent":10,"message":"Starting app services"}
Nov 26 10:07:58 box:tasks update 4382: {"percent":35,"message":"Starting container"}
Nov 26 10:07:59 ==> starting server
Nov 26 10:07:59 box:tasks update 4382: {"percent":60,"message":"Adding collectd profile"}
Nov 26 10:07:59 box:shell addCollectdProfile spawn: /usr/bin/sudo -S /home/yellowtent/box/src/scripts/configurecollectd.sh add 7962ae53-502c-4c68-b1eb-580da056615c
Nov 26 10:07:59 box:shell addCollectdProfile (stdout): Restarting collectd
Nov 26 10:07:59 box:tasks update 4382: {"percent":80,"message":"Configuring reverse proxy"}
Nov 26 10:07:59 box:reverseproxy ensureCertificate: AAAA.CCCCC.XXX certificate already exists at /home/yellowtent/platformdata/nginx/cert/_.CCCCC.XXX.key
Nov 26 10:07:59 box:reverseproxy expiryDate: /home/yellowtent/platformdata/nginx/cert/_.CCCCC.XXX.cert notAfter=Jan 14 22:09:55 2022 GMT daysLeft=49.54300729166667
Nov 26 10:07:59 box:reverseproxy providerMatchesSync: /home/yellowtent/platformdata/nginx/cert/_.CCCCC.XXX.cert subject=CN = *.CCCCC.XXX domain=*.CCCCC.XXX issuer=C = US, O = Let's Encrypt, CN = R3 wildcard=true/true prod=true/true issuerMismatch=false wildcardMismatch=false match=true
Nov 26 10:07:59 box:reverseproxy writeAppNginxConfig: writing config for "AAAA.CCCCC.XXX" to /home/yellowtent/platformdata/nginx/applications/7962ae53-502c-4c68-b1eb-580da056615c.conf with options {"sourceDir":"/home/yellowtent/box","vhost":"AAAA.CCCCC.XXX","hasIPv6":true,"ip":"172.18.19.48","port":3000,"endpoint":"app","certFilePath":"/home/yellowtent/platformdata/nginx/cert/_.CCCCC.XXX.cert","keyFilePath":"/home/yellowtent/platformdata/nginx/cert/_.CCCCC.XXX.key","robotsTxtQuoted":"\"# Disable search engine indexing\\n\\nUser-agent: *\\nDisallow: /\"","cspQuoted":null,"hideHeaders":[],"proxyAuth":{"enabled":false,"id":"7962ae53-502c-4c68-b1eb-580da056615c","location":"/"},"ocsp":true}
Nov 26 10:07:59 box:shell reload spawn: /usr/bin/sudo -S /home/yellowtent/box/src/scripts/restartservice.sh nginx
Nov 26 10:07:59
Nov 26 10:07:59 > @joplin/server@2.6.12 start
Nov 26 10:07:59 > node dist/app.js
Nov 26 10:07:59
Nov 26 10:07:59 box:tasks update 4382: {"percent":100,"message":"Done"}
Nov 26 10:07:59 box:taskworker Task took 0.802 seconds
Nov 26 10:07:59 box:tasks setCompleted - 4382: {"result":null,"error":null}
Nov 26 10:07:59 box:tasks update 4382: {"percent":100,"result":null,"error":null}

****
Nov 26 10:08:01 2021-11-26 09:08:01: App: Starting server v2.6.12 (prod) on port 3000 and PID 32...
Nov 26 10:08:01 Error: The device time drift is 581503ms (Max allowed: 100ms) - cannot continue as it could cause data loss and conflicts on the sync clients. You may increase env var MAX_TIME_DRIFT to pass the check.
****

Nov 26 10:08:01 at /app/code/packages/server/src/app.ts:256:10
Nov 26 10:08:01 at Generator.next (<anonymous>)
Nov 26 10:08:01 at fulfilled (/app/code/packages/server/dist/app.js:5:58)
Nov 26 10:08:01 at processTicksAndRejections (node:internal/process/task_queues:96:5)
Nov 26 10:08:01 ==> starting server
Nov 26 10:08:02
Nov 26 10:08:02 > @joplin/server@2.6.12 start
Nov 26 10:08:02 > node dist/app.js
Nov 26 10:08:02

****
Nov 26 10:08:03 2021-11-26 09:08:03: App: Starting server v2.6.12 (prod) on port 3000 and PID 30...
Nov 26 10:08:03 Error: The device time drift is 581503ms (Max allowed: 100ms) - cannot continue as it could cause data loss and conflicts on the sync clients. You may increase env var MAX_TIME_DRIFT to pass the check.
****

Nov 26 10:08:03 at /app/code/packages/server/src/app.ts:256:10
Nov 26 10:08:03 at Generator.next (<anonymous>)
Nov 26 10:08:03 at fulfilled (/app/code/packages/server/dist/app.js:5:58)
Nov 26 10:08:03 at processTicksAndRejections (node:internal/process/task_queues:96:5)
Nov 26 10:08:04 ==> starting server
Nov 26 10:08:04
Nov 26 10:08:04 > @joplin/server@2.6.12 start
Nov 26 10:08:04 > node dist/app.js
Nov 26 10:08:04

****
Nov 26 10:08:05 2021-11-26 09:08:05: App: Starting server v2.6.12 (prod) on port 3000 and PID 30...
Nov 26 10:08:05 Error: The device time drift is 581503ms (Max allowed: 100ms) - cannot continue as it could cause data loss and conflicts on the sync clients. You may increase env var MAX_TIME_DRIFT to pass the check.
****

Nov 26 10:08:05 at /app/code/packages/server/src/app.ts:256:10
Nov 26 10:08:05 at Generator.next (<anonymous>)
Nov 26 10:08:05 at fulfilled (/app/code/packages/server/dist/app.js:5:58)
Nov 26 10:08:05 at processTicksAndRejections (node:internal/process/task_queues:96:5)

Do you have any need/interest to know about hardware, etc? (I'm assuming "device time drift" is related to hardware.)

[fbartels]

@ei8fdb said in Joplin Server not Responding (2.6.12):

The device time drift is 581488ms (Max allowed: 10ms)

I would guess the value of "100" for MAX_TIME_DRIFT is still milliseconds, which would mean the value is too small for your drift. The root cause for you however seems to be that the time on your server is simply lagging behind/infront. I would check if ntp is properly setup and running. 581488ms means your system is off by almost 10 minutes and this could also cause issues with tokens issued by other services.

[ei8fdb]

@fbartels said in Joplin Server not Responding (2.6.12):

I would guess the value of "100" for MAX_TIME_DRIFT is still milliseconds, which would mean the value is too small for your drift. The root cause for you however seems to be that the time on your server is simply lagging behind/infront. I would check if ntp is properly setup and running. 581488ms means your system is off by almost 10 minutes and this could also cause issues with tokens issued by other services.

Ah yes @fbartels you are absolutely right. I totally missed the 581488ms = 10 mins, which is how much the clock was off. I thought that ntp was already installed by Cloudron but it wasn't. Thanks for pointing that out.

Once I installed and configured it the Joplin server restarted on the upgraded version (org.joplinapp.cloudron@1.2.7).

@neurokrish if you confirm the system clock on your server is off, check your ntp configuration. If off, fix it. If ntp is not installed, install and configure it. Then restart your Joplin server. It should start then.

[neurokrish]

@fbartels @girish yes, just checked. This is a time drift issue. I looked at the changelog for Joplin server and they mention that there is a new feature to check for timedrift when the server starts. I added MAX_TIME_DRIFT=100 and the server started without any issues. Thank you everyone for help. Please close this issue!