Text editor loses connection regularly

ℹ️ Support
1

Nextcloud version (eg, 18.0.2): 19.04
Operating system and version (eg, Ubuntu 20.04): CentOS (shared hoster uberspace.de)
Apache or nginx version (eg, Apache 2.4.25):
PHP version (eg, 7.1):

The issue you are facing: If I edit markdown documents via the embedded web texteditor, it loses regularly the sync:

file could not be loaded. Please check your internet connection (retry)

This occurs right after a few minutes and I guess a tip faster if you are on a edit. This error occurs on different internet connections.

Is this the first time you’ve seen this error? (Y/N): Y

Steps to replicate it:

  1. Open Files app on your cloud webinterface
  2. Click a textfile to edit
  3. Start writing to the opened file and wait till the above poppup message appears
  4. Click rety and note, that nothing will reload. So reload the whole page

The output of your Nextcloud log in Admin > Logging:

Info	files_versions	Expire: /todo-neu.md.v1604050096	
2020-10-31T14:46:45+0100
Info	files_versions	Expire: /todo-neu.md.v1604146048	
2020-10-31T14:46:45+0100
Info	files_versions	Expire: /todo-neu.md.v1604146364	
2020-10-31T14:46:45+0100
Info	files_versions	Expire: /todo-neu.md.v1604146489	
2020-10-31T14:46:45+0100
Info	files_versions	Expire: /todo-neu.md.v1604146882	
2020-10-31T14:46:45+0100
Info	files_versions	Mark to expire /todo-neu.md next version should be 1603975689 or smaller. (prevTimestamp: 1604062089; step: 86400	
2020-10-31T14:46:44+0100
Info	files_versions	Mark to expire /todo-neu.md next version should be 1604143669 or smaller. (prevTimestamp: 1604147269; step: 3600	
2020-10-31T14:46:44+0100
Info	files_versions	Mark to expire /todo-neu.md next version should be 1604143669 or smaller. (prevTimestamp: 1604147269; step: 3600	
2020-10-31T14:46:44+0100
Info	files_versions	Mark to expire /todo-neu.md next version should be 1604143669 or smaller. (prevTimestamp: 1604147269; step: 3600	
2020-10-31T14:46:44+0100
Info	files_versions	Mark to expire /todo-neu.md next version should be 1604143669 or smaller. (prevTimestamp: 1604147269; step: 3600	
2020-10-31T14:46:44+0100

The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):

PASTE HERE

The output of your Apache/nginx/system log in /var/log/____:

PASTE HERE
1 Like
2

I can confirm this issue. The editor becomes unusable

3
4

I’ve run into exactly the same problem.

This issue is that no cache has been set. The Nextcloud documentation indicates that setting a cache is not required. While this is true, the fact that no cache has been set means that the Text Editor application disconnects immediately once typing has stopped. The application attempts to perform a Save using the cache… but there is no cache… and so the application produces the error message and requests to be reconnected.

The solution to this problem is enabling a local cache using the instructions in the Nextcloud documentation:

https://docs.nextcloud.com/server/24/admin_manual/configuration_server/caching_configuration.html

After enabling the APCu and memcached utilities exactly as described above, the error message goes away and the text editor application runs quite smoothly.

1 Like
5

I’ve got this problem too, but I’m not sure it’s from the same cause, because I’ve turned on ACPu caching and opcache.

2023-01-27-205038_1360x151_scrot
2023-01-27-205038_1360x151_scrot1360×151 13.8 KB

The config checker reports only that I haven’t turned on HSTS yet, and that I’m running php7 when it really wants me to be running php8:

2023-01-27-210230_988x258_scrot
2023-01-27-210230_988x258_scrot988×258 37.3 KB

NextCloud version: 25.0.3.2
Operating system version: Debian GNU/Linux 11 (bullseye)
nginx version: 1.18.0-6.1+deb11u3
PHP: 7.4.33-1+deb11u1

Admin > Logging:

There are no log messages in here that overlap anywhere close to the same timestamps.

/var/www/nextcloud/config/config.php:

<?php
$CONFIG = array (
  'instanceid' => 'REDACTED',
  'passwordsalt' => 'REDACTED',
  'secret' => 'REDACTED',
  'trusted_domains' => 
  array (
    0 => 'REDACTED',
  ),
  'datadirectory' => '/var/www/nextcloud/data',
  'dbtype' => 'mysql',
  'version' => '25.0.3.2',
  'overwrite.cli.url' => 'REDACTED',
  'dbname' => 'nextcloud',
  'dbhost' => 'localhost',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'mysql.utf8mb4' => true,
  'dbuser' => 'REDACTED',
  'dbpassword' => 'REDACTED',
  'installed' => true,
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'default_phone_region' => 'CA',
  'maintenance' => false,
  'mail_from_address' => 'nextcloud',
  'mail_smtpmode' => 'smtp',
  'mail_sendmailmode' => 'smtp',
  'mail_domain' => 'REDACTED',
  'mail_smtpauthtype' => 'LOGIN',
  'mail_smtpauth' => 1,
  'mail_smtphost' => 'REDACTED',
  'mail_smtpport' => '587',
  'mail_smtpname' => 'REDACTED',
  'mail_smtppassword' => 'REDACTED',
  'app_install_overwrite' => 
  array (
    0 => 'files_ebookreader',
  ),
  'theme' => '',
  'loglevel' => 2,
);
?>

/var/log/nginx/access.log:

XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:18 -0500] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 304 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:21 -0500] "GET /apps/logreader/poll?lastReqId=lyWTNeBDFaYPJwgcz2Mh HTTP/1.1" 200 22 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:41 -0500] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 304 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:41 -0500] "GET /apps/logreader/poll?lastReqId=lyWTNeBDFaYPJwgcz2Mh HTTP/1.1" 200 22 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:43 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 231 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:44 -0500] "POST /apps/text/session/push HTTP/1.1" 200 97 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:44 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 297 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:45 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 234 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:45 -0500] "POST /apps/text/session/push HTTP/1.1" 200 127 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:45 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 321 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:45 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 234 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:46 -0500] "POST /apps/text/session/push HTTP/1.1" 200 251 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:46 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 458 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:46 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 235 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:48 -0500] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 304 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:48 -0500] "POST /apps/text/session/push HTTP/1.1" 200 126 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:48 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 333 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:49 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 234 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:54 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 233 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:49:59 -0500] "POST /apps/text/session/sync HTTP/1.1" 200 233 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:01 -0500] "PUT /ocs/v2.php/apps/user_status/api/v1/heartbeat?format=json HTTP/1.1" 200 112 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:01 -0500] "GET /apps/logreader/poll?lastReqId=lyWTNeBDFaYPJwgcz2Mh HTTP/1.1" 200 22 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:10 -0500] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 304 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:18 -0500] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 304 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:19 -0500] "PUT /ocs/v2.php/apps/user_status/api/v1/heartbeat?format=json HTTP/1.1" 200 112 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:27 -0500] "GET /apps/logreader/poll?lastReqId=lyWTNeBDFaYPJwgcz2Mh HTTP/1.1" 200 22 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:40 -0500] "PUT /ocs/v2.php/apps/user_status/api/v1/heartbeat?format=json HTTP/1.1" 200 112 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:40 -0500] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 304 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"
XXX.XXX.XXX.XXX - - [27/Jan/2023:20:50:43 -0500] "PUT /ocs/v2.php/apps/user_status/api/v1/heartbeat?format=json HTTP/1.1" 200 112 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36"

/var/log/nginx/error.log:

2023/01/27 20:50:06 [alert] 1017#1017: *1 open socket #3 left in connection 5
2023/01/27 20:50:06 [alert] 1017#1017: *312 open socket #13 left in connection 6
2023/01/27 20:50:06 [alert] 1017#1017: *9 open socket #18 left in connection 11
2023/01/27 20:50:06 [alert] 1017#1017: *336 open socket #15 left in connection 17
2023/01/27 20:50:06 [alert] 1017#1017: aborting

Also, in my browser, I got these errors in the javascript console:

index.js:323 OC.requestToken changed o6gul9nmlr1OQdFBMTCQtldBTcqjX6KbfBChv+ZrIfU=:z+JGrpWk7tkpBfomc1TB+z0zdJjVDNXcKUDn5dU8TcU=

ConsoleLogger.js:46 [ERROR] text: Failed to fetch steps due to other reason {level: 2, app: 'text', uid: 'USERNAME', error: i}
value @ ConsoleLogger.js:46
value @ ConsoleLogger.js:72
value @ PollingBackend.js:208
Promise.then (async)
value @ PollingBackend.js:132
setInterval (async)
value @ PollingBackend.js:292
value @ PollingBackend.js:158
Promise.then (async)
value @ PollingBackend.js:132
setInterval (async)
value @ PollingBackend.js:292
value @ PollingBackend.js:158
Promise.then (async)
value @ PollingBackend.js:132
setInterval (async)
value @ PollingBackend.js:292
value @ PollingBackend.js:158
Promise.then (async)
value @ PollingBackend.js:132
setInterval (async)
value @ PollingBackend.js:273
value @ PollingBackend.js:171
Promise.then (async)
value @ PollingBackend.js:132
value @ PollingBackend.js:104
(anonymous) @ PollingBackend.js:235
Promise.then (async)
value @ PollingBackend.js:232
value @ SyncService.js:168
onSendable @ Editor.vue:533
t @ Collaboration.js:28
(anonymous) @ Collaboration.js:16
setTimeout (async)
getSendableSteps @ Collaboration.js:15
(anonymous) @ Collaboration.js:40
(anonymous) @ tiptap-core.esm.js:166
emit @ tiptap-core.esm.js:166
dispatchTransaction @ tiptap-core.esm.js:3545
dispatch @ index.js:5301
an @ index.js:4749
(anonymous) @ index.js:4928
flush @ index.js:4393
observer @ index.js:4249

xhr.js:220          POST https://REDACTED/apps/text/session/sync net::ERR_CONNECTION_REFUSED
(anonymous) @ xhr.js:220
e.exports @ xhr.js:16
e.exports @ dispatchRequest.js:56
d.request @ Axios.js:109
(anonymous) @ Axios.js:144
(anonymous) @ bind.js:9
value @ PollingBackend.js:122
setInterval (async)
value @ PollingBackend.js:292
value @ PollingBackend.js:158
Promise.then (async)
value @ PollingBackend.js:132
setInterval (async)
value @ PollingBackend.js:292
value @ PollingBackend.js:158
Promise.then (async)
value @ PollingBackend.js:132
setInterval (async)
value @ PollingBackend.js:292
value @ PollingBackend.js:158
Promise.then (async)
value @ PollingBackend.js:132
setInterval (async)
value @ PollingBackend.js:273
value @ PollingBackend.js:171
Promise.then (async)
value @ PollingBackend.js:132
value @ PollingBackend.js:104
(anonymous) @ PollingBackend.js:235
Promise.then (async)
value @ PollingBackend.js:232
value @ SyncService.js:168
onSendable @ Editor.vue:533
t @ Collaboration.js:28
(anonymous) @ Collaboration.js:16
setTimeout (async)
getSendableSteps @ Collaboration.js:15
(anonymous) @ Collaboration.js:40
(anonymous) @ tiptap-core.esm.js:166
emit @ tiptap-core.esm.js:166
dispatchTransaction @ tiptap-core.esm.js:3545
dispatch @ index.js:5301
an @ index.js:4749
(anonymous) @ index.js:4928
flush @ index.js:4393
observer @ index.js:4249

index.js:323 OC.requestToken changed 4RtrpIiJLZzgwmGlSUhYeKa7ro8Z6VJgqwep234T+5E=:jVEDncTLVfiHhkrCCywJNczJl91vuiUn/lfvgU1El6E=

So it looks like for some reason I’m getting throttled from hitting /apps/text/session/sync? Is it perhaps an nginx setting I need to turn up? Maybe it’s ulimits? Anyone else have anything else like this?

6

Ah I think I can reproduce it; I did copy-as-cURL from my browser and turned it into this script:

#!/bin/sh
# /tmp/curl.sh

curl 'https://REDACTED/apps/text/session/sync' \
  -H 'Accept: application/json, text/plain, */*' \
  -H 'Accept-Language: en-GB,en-US;q=0.9,en;q=0.8' \
  -H 'Connection: keep-alive' \
  -H 'Content-Type: application/json' \
  -H 'Cookie: __Host-nc_sameSiteCookielax=true; __Host-nc_sameSiteCookiestrict=true; nc_username=kousu; oc_sessionPassphrase=REDACTED; REDACTED=gv56s15b318podr1juhch8oo7j; nc_token=REDACTED; nc_session_id=REDACTED' \
  -H 'Origin: https://org.yota.space' \
  -H 'Sec-Fetch-Dest: empty' \
  -H 'Sec-Fetch-Mode: cors' \
  -H 'Sec-Fetch-Site: same-origin' \
  -H 'User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36' \
  -H 'requesttoken: REDACTED' \
  -H 'sec-ch-ua: "Chromium";v="109", "Not_A Brand";v="99"' \
  -H 'sec-ch-ua-mobile: ?0' \
  -H 'sec-ch-ua-platform: "Linux"' \
  --data-raw '{"documentId":475,"sessionId":247,"sessionToken":"REDACTED","version":18,"force":false,"manualSave":false,"token":null,"filePath":"/Site/NextCloud.md"}' \
  --compressed

Then I pounded my server by hitting it with 1000 parallel connections:

seq 1000 | xargs -n 1 -P 0 /tmp/curl.sh

Most of the connections succeeded:

{"steps":[],"sessions":[{"id":247,"userId":"USER","token":"","color":"#93b27b","lastContact":1674873178,"guestName":null,"documentId":475,"displayName":"kousu"}],"document":{"id":475,"currentVersion":18,"lastSavedVersion":18,"lastSavedVersionTime":1674872828,"baseVersionEtag":"3d196eca5d493aef29eadefedbdc7c74","initialVersion":0}}

but some of them gave me

curl: (35) OpenSSL SSL_connect: SSL_ERROR_SYSCALL in connection to org.yota.space:443

I haven’t solved it yet but being able to reproduce will hopefully help.

It’s too bad that NextCloud just like, gives up when it gets a connection refused? Instead of backing off and trying to reconnect later.

I grabbed a monitoring script from https://stackoverflow.com/a/21752125:

# cat /tmp/scan
#!/bin/sh

find /proc -maxdepth 1 -type d -name '[0-9]*' \
     -exec bash -c "ls {}/fd/ | wc -l | tr '\n' ' '" \; \
     -printf "fds (PID = %P), command: " \
     -exec bash -c "tr '\0' ' ' < {}/cmdline" \; \
     -exec echo \; | sort -rn | head

and used

watch sh /tmp/scan

while my load-generating xargs script was running. During this, I was able to capture these screenshots:

2023-01-27-214833_1366x768_scrot
2023-01-27-214833_1366x768_scrot736×308 11.8 KB

since 775 is pretty close to the 1024 open file limit, I wouldn’t be surprised if that was the cause. Or maybe it’s the

www-data@org:~$ ulimit  -a
real-time non-blocking time  (microseconds, -R) unlimited
core file size              (blocks, -c) 0
data seg size               (kbytes, -d) unlimited
scheduling priority                 (-e) 0
file size                   (blocks, -f) unlimited
pending signals                     (-i) 7656
max locked memory           (kbytes, -l) 248003
max memory size             (kbytes, -m) unlimited
open files                          (-n) 1024
pipe size                (512 bytes, -p) 8
POSIX message queues         (bytes, -q) 819200
real-time priority                  (-r) 0
stack size                  (kbytes, -s) 8192
cpu time                   (seconds, -t) unlimited
max user processes                  (-u) 7656
virtual memory              (kbytes, -v) unlimited
file locks                          (-x) unlimited

or even more suspiciously, it’s pretty close to the worker_connections 768; limit in nginx.

But this is artificial load. Is it really true that a single browser window can cause the same spike?

EDIT:

I don’t think the artificial load is an accurate reproduction.

I also tried changed nginx’s worker_connections to 10, and to 10000, and it was the same either way, so I don’t think that has anything to do with it.