Slow desktop client sync

Nextcloud version (eg, 19.0.3):
Operating system and version (QNAP QTS 4.4.3+Docker):
Apache or nginx version (Docker image 19.0.3):
CPU: Celeron J1900 @ 1.99GHz (4*cores)
RAM: 8GB

initially posted as comment to https://help.nextcloud.com/t/up-download-to-slow-only-2mb-s-after-installation-despite-good-hardware/96105/15 but break out to own topic due to recommendation of @KarlF12

it takes multiple days to perform initial sync to the clients - both on Win and Linux in local LAN with 1GBits/s. The folder contains 70k files with 40GB. I have local DNS server which points Nextcloud FQDN to local IP so there is no loop through Internet (split-brain DNS). I don’t see exhausted resource on server: CPU is running 30%-70% plenty of RAM is free, no error messages. if there is a big file I see transfer speeds up to 50-70 MB/s but the average is really bad as often it only syncs 1-2 files per seconds and consumes only few KB/s of network bandwidth. There are some directories with hundreds of small files (thumbnails of photo book software) - here I observe only 1-2 files are processed per second.

Upload/Download via Browser works with 4-30 MB/s.

download via Browser
image

Upload via Browser
image

I made a test and uploaded a video vile with 134MB with a browser - it took ~20 sec with very little pauses every 10MB (chunks) the speed shown in the progress bar was 3MB/s to 20MB/s. The file appeared on the clients local directory 30 sec later - sync took ~6 sec according to the client log, which is absolutely acceptable and shows disk and network perform fast. The problem I have is when lot of small files exist on a directory it takes ages…

2020-10-27 13:30:03:934 [ info nextcloud.gui.application ]:	Sync state changed for folder  "https://<my.nextcloud.fqdn>/remote.php/dav/files/<user>/Documents" :  "Sync Running"
2020-10-27 13:30:03:935 [ info nextcloud.sync.propagator ]:	Starting INSTRUCTION_NEW propagation of "Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4" by OCC::PropagateDownloadFile(0x219c4d63090)
2020-10-27 13:30:03:936 [ info nextcloud.sync.accessmanager ]:	2 "" "https://<my.nextcloud.fqdn>/remote.php/dav/files/<user>/Documents/Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4" has X-Request-ID "d30cff50-5b8f-4fb6-92f8-2a3fc1ce6c0a"
2020-10-27 13:30:03:937 [ info nextcloud.sync.networkjob ]:	OCC::GETFileJob created for "https://<my.nextcloud.fqdn>" + "/Documents/Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4" "OCC::PropagateDownloadFile"
2020-10-27 13:30:04:491 [ info nextcloud.sync.credentials.webflow ]:	request finished
2020-10-27 13:30:04:491 [ info nextcloud.sync.networkjob.etag ]:	Request Etag of QUrl("https://<my.nextcloud.fqdn>/remote.php/dav/files/<user>/Contacts") FINISHED WITH STATUS "OK"
2020-10-27 13:30:08:313 [ info nextcloud.sync.credentials.webflow ]:	request finished
2020-10-27 13:30:08:326 [ info nextcloud.sync.checksums ]:	Computing "SHA1" checksum of "W:/Nextcloud/Documents/.Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4.~fa9" in a thread
2020-10-27 13:30:08:660 [ info nextcloud.sync.database ]:	Updating file record for path: "Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4" inode: 53 modtime: 1507790579 type: 0 etag: "e8cc653832d587e1493e7a777b34c60f" fileId: "00475173ocshh0oigtc5" remotePerm: "WDNVR" fileSize: 140892641 checksum: "SHA1:d2021affa8db72d65f0220b44f07004a74eef3e9" e2eMangledName: "" isE2eEncrypted: false
2020-10-27 13:30:08:662 [ info nextcloud.sync.propagator ]:	Completed propagation of "Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4" by OCC::PropagateDownloadFile(0x219c4d63090) with status 4
2020-10-27 13:30:08:662 [ warning nextcloud.gui.activity ]:	Item  "Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4"  retrieved resulted in  ""
2020-10-27 13:30:08:663 [ warning nextcloud.gui.activity ]:	Item  "Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4"  retrieved successfully.
2020-10-27 13:30:08:663 [ info nextcloud.gui.activity ]:	Successfully added to the activity list:  ""
2020-10-27 13:30:08:664 [ info nextcloud.gui.folderwatcher ]:	Detected changes in paths: QSet("W:/Nextcloud/Documents/Ask me anything, with Mark Russinovich on cloud, Sysinternals, security, and more-P1pk9VBdwUs.mp4")
2020-10-27 13:30:08:665 [ info nextcloud.sync.database ]:	Closing DB "C:/Users/<user>/AppData/Roaming/Nextcloud/._sync_6d0d8033c51e.db"
2020-10-27 13:30:08:675 [ info nextcloud.sync.engine ]:	CSync run took  6145 ms

from the log it look like the client i doing many many thing just to replicate one file - is it expected?

The file appeared on the local client few seconds later. I checked the client log during the sync and see it executed bunch SQL queries for ALL existing files in the directory where I put the upload is this expected?

2020-10-27 13:16:02:962 [ info nextcloud.sync.csync.updater ]:	Database entry found for Readme.md, compare: 1597168289 <-> 1597168289, etag: 0aba3361429e9afd483f17bb8be7644a <-> 0aba3361429e9afd483f17bb8be7644a, inode: 0 <-> 1116, size: 136 <-> 136, perms: 9f <-> 9f, checksum:  <->  , ignore: 0,  e2e: 
2020-10-27 13:16:02:962 [ info nextcloud.sync.csync.updater ]:	file: Readme.md, instruction: INSTRUCTION_NONE <<=
2020-10-27 13:16:02:962 [ debug nextcloud.sync.csync.updater ]	[ csync_walker ]:	file: Welcome to Nextcloud Hub.docx [file_id=00000210ocshh0oigtc5 size=25150]
2020-10-27 13:16:02:963 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::bindValue ]:	SQL bind 1 QVariant(qlonglong, 3622897607555501721)
2020-10-27 13:16:02:963 [ debug nextcloud.sync.database.sql ]	[ OCC::SqlQuery::exec ]:	SQL exec "SELECT path, inode, modtime, type, md5, fileid, remotePerm, filesize,  ignoredChildrenRemote, contentchecksumtype.name || ':' || contentChecksum, e2eMangledName, isE2eEncrypted  FROM metadata  LEFT JOIN checksumtype as contentchecksumtype ON metadata.contentChecksumTypeId == contentchecksumtype.id WHERE phash=?1"

I already tuned my mysql with the following settings:

innodb_flush_log_at_trx_commit = 2
innodb_flush_log_at_timeout = 5
max_connections = 250

which made the system feel little more responsive but still not really good to sync thousands of files. having max_connections = 100 I had an error in the logs that DB stopped responding because of “too many connections” - why does the system with 2 users and 3 clients need more then 100 sql connections?

docker stats shows my Nextcloud container spiking from 0 to 130% cpu all the time (every 1-2 seconds)

CONTAINER           CPU %               MEM USAGE / LIMIT     MEM %               NET I/O             BLOCK I/O           PIDS
f3cbbca40b9d        130.33%             106.6MiB / 7.671GiB   1.36%               451GB / 111GB       183GB / 858MB       0

But syncing small files is terribly slow - I see the client only syncs 1-2 small files per second - even this are only KB. Web interface is pretty slow on initial load 5-10 sec spinning after entering a folder - but once it’s loaded one can view/download files really fast. I don’t see any errors in logs.

@KarlF12 assumed the disk is slow - from my feeling disk speed is not an issue as big files transfer fast. Copying the data from/to the system via NFS or SMB is fast and saturates the 1GBit/s network adapter. I run the speed test as recommended by @KarlF12 read test performed after clearing caches. The speed looks quite good for me…


#sync; dd if=/dev/zero of=./ddtestfile bs=1M count=1024;sync
1024+0 records in
1024+0 records out
1073741824 bytes (1.0GB) copied, 8.834910 seconds, 115.9MB/s

# sync; dd if=./ddtestfile of=/dev/null bs=1M count=1024;sync
1024+0 records in
1024+0 records out
1073741824 bytes (1.0GB) copied, 10.101529 seconds, 101.4MB/s

# hdparm -Tt /dev/md0
/dev/md0:
 Timing cached reads:   4804 MB in  2.00 seconds = 2403.63 MB/sec
HDIO_DRIVE_CMD(null) (wait for flush complete) failed: Inappropriate ioctl for device
 Timing buffered disk reads:  394 MB in  3.01 seconds = 131.09 MB/sec
HDIO_DRIVE_CMD(null) (wait for flush complete) failed: Inappropriate ioctl for device

The output of your Nextcloud log in Admin > Logging:

#can't upload the log due to post limits, the message are more or less the same majority of the logs are:
not enough messages to train a classifier

#and once an hour there is such message:
OCA\Mail\Exception\ServiceException: IMAP errorError connecting to mail server.

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

<?php
$CONFIG = array (
  'htaccess.RewriteBase' => '/',
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'apps_paths' => 
  array (
    0 => 
    array (
      'path' => '/var/www/html/apps',
      'url' => '/apps',
      'writable' => false,
    ),
    1 => 
    array (
      'path' => '/var/www/html/custom_apps',
      'url' => '/custom_apps',
      'writable' => true,
    ),
  ),
  'memcache.distributed' => '\\OC\\Memcache\\Redis',
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'redis' => 
  array (
    'host' => 'nextcloud-redis',
    'password' => '***SECRET***',
    'port' => 6379,
  ),
  'instanceid' => 'ocshh0oigtc5',
  'passwordsalt' => '***SECRET***',
  'secret' => '***SECRET***',
  'trusted_domains' => 
  array (
    0 => '<my.nextcloud.fqdn>',
  ),
  'datadirectory' => '/var/www/html/data',
  'dbtype' => 'mysql',
  'version' => '19.0.3.1',
  'overwrite.cli.url' => 'https://<my.nextcloud.fqdn>',
  'dbname' => 'nextcloud',
  'dbhost' => 'nextcloud-db',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'mysql.utf8mb4' => true,
  'dbuser' => 'nextcloud',
  'dbpassword' => '***SECRET***',
  'installed' => true,
  'overwritehost' => '<my.nextcloud.fqdn>',
  'overwriteprotocol' => 'https',
  'mail_smtpmode' => 'smtp',
  'mail_sendmailmode' => 'smtp',
  'mail_from_address' => 'nextcloud',
  'mail_domain' => '***SECRET***',
  'mail_smtphost' => '***SECRET***',
  'mail_smtpauth' => 1,
  'mail_smtpname' => '***SECRET***',
  'mail_smtppassword' => '***SECRET***',
  'mail_smtpport' => '465',
  'mail_smtpauthtype' => 'PLAIN',
  'mail_smtpsecure' => 'ssl',
  'maintenance' => false,
  'trusted_proxies' => 
  array (
    0 => '\'traefik',
    1 => '172.16.0.0/12',
    2 => '192.168.0.0/16',
    3 => '10.0.0.0/8\'',
  ),
  'theme' => '',
  'loglevel' => 2,
);

[

That’s quite a lot of allowed reverse proxy IPs. Have you tried syncing without the reverse proxy to see if speed improves?

I made a step towards the solution: disabling “External storage” app made it sync really fast (and website is much more responsive as well) - now I see 10-20 very small files per second (1-2 before). I used external storage to connect with 3 SMB file shares. I have to analyze further why it such dramatically reduces the performance - most likely external storage app performs some actions on every file access - even this is stored locally within Nextcloud.

Update: With external storage disabled I see replication of ~10-20 small files per second (had 1-2 before!!) using ~100-200 kBit/s (10-15 before) which is at least 10 times faster! The complete sync of one client took 2-3 hours. the same operation didn’t completed within 3 days with external storage enabled.

The problem is definitely located within external storage app.

I added another topic with the detailed tests:

replication 106 files with a size of 700kB takes

  • 44 sec without external storage
  • 135 sec with 3 active SMB mounts

so this must be some bug within external storage app