Server very slow doing file move and other similar operations

Support intro

Sorry to hear you’re facing problems :slightly_frowning_face:

help.nextcloud.com is for home/non-enterprise users. If you’re running a business, paid support can be accessed via portal.nextcloud.com where we can ensure your business keeps running smoothly.

In order to help you as quickly as possible, before clicking Create Topic please provide as much of the below as you can. Feel free to use a pastebin service for logs, otherwise either indent short log examples with four spaces:

example

Or for longer, use three backticks above and below the code snippet:

longer
example
here

Some or all of the below information will be requested if it isn’t supplied; for fastest response please provide as much as you can :heart:

Nextcloud version (eg, 29.0.5): 29.0.3
Operating system and version (eg, Ubuntu 29.04): Ubuntu 22.04.4 LTS
Apache or nginx version (eg, Apache 2.4.25): Apache/2.4.52
PHP version (eg, 8.3): PHP Version 8.1.2-1ubuntu2.18

The issue you are facing:

File operations (upload, rename/move) are extremely slow. For example, MOVE commands are currently taking between 12 and 30 seconds per file.

Other info:

  • mysql slow query logging at 2 seconds shows no correlated slow queries
  • php-fpm in use
  • running non-virtualized on (basically) dedicated server with i7 CPU, 8gb ram, newer HDD
  • uptime load typically around 2-3
  • htop shows 2.6gb out of 8 used; low CPU (<10%) all around
  • NC setup warnings are minimal: Your web server is not properly set up to resolve .well-known URLs, server has no maintenance window start time configured, some headers are not set correctly on your instance (only security-related stuff)
  • NC is maintaining around 115,000 files taking up 414 GB
  • All files are for a single user; it’s basically a one user system

Is this the first time you’ve seen this error? No. This started occurring perhaps a year ago and I keep NC version pretty well updated to the most recent stable version.

Steps to replicate it:

Move a file from one directory to another either via the web UI or desktop sync client

The output of your Nextcloud log in Admin > Logging:

No warning or error level information is related to this problem

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

<?php
$CONFIG = array (
  'instanceid' => 'XXX',
  'passwordsalt' => 'XXX',
  'secret' => 'XXX',
  'allow_local_remote_servers' => true,
  'trusted_domains' =>
  array (
    0 => 'localhost',
    1 => '192.168.1.101',
    2 => 'XXX',
    3 => 'XXX.lan',
    4 => 'ZZZ',
    5 => '192.168.1.100',
    6 => 'YYY',
    7 => 'YYY.lan',
  ),
  'datadirectory' => '/var/www/nextcloud/data',
  'default_phone_region' => 'US',
  'dbtype' => 'mysql',
  'version' => '29.0.3.4',
  'overwrite.cli.url' => 'http://192.168.1.101/nextcloud',
  'dbname' => 'nextcloud',
  'dbhost' => 'localhost',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'filelocking.enabled' => true,
  'mysql.utf8mb4' => true,
  'dbuser' => 'oc_admin',
  'dbpassword' => 'XXX',
  'installed' => true,
  'log_type' => 'file',
  'logfile' => '/var/log/nextcloud/nextcloud.log',
  'loglevel' => 2,
  'logdateformat' => 'F d, Y H:i:s',
  'maintenance' => false,
  'mail_from_address' => 'XXX',
  'mail_smtpmode' => 'sendmail',
  'mail_domain' => 'XXX',
  'mail_smtphost' => 'aspmx.l.google.com',
  'mail_smtpport' => '25',
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'memcache.local' => '\\OC\\Memcache\\Redis',
  'redis' =>
  array (
    'host' => 'localhost',
    'port' => 6379,
  ),
  'mail_smtpauthtype' => 'LOGIN',
  'mail_smtpauth' => 1,
  'theme' => '',
);

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

Note that I added a first column which is seconds to process request (e.g. 14 below is 14s to process that MOVE). I’ve included several other types of requests to illustrate that some are almost instant.

access.log:

14 192.168.1.100 - - [28/Jun/2024:13:27:19 -0500] "MOVE /nextcloud/remote.php/dav/files/chris/Pictures/2024/2024-06/2024_06_20%20IMG_1122.jpg HTTP/1.1" 201 755 "-" "Mozilla/5.0 (Windows) mirall/3.13.0stable-Win64 (build 20240423) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
0 199.204.58.31 - - [28/Jun/2024:13:27:38 -0500] "GET /nextcloud/index.php/apps/logreader/api/poll?lastReqId=OiFb8VC3hfkucstkCzrW HTTP/2.0" 200 556 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36 Edg/126.0.0.0"
0 199.204.58.31 - - [28/Jun/2024:13:27:39 -0500] "PUT /nextcloud/ocs/v2.php/apps/user_status/api/v1/heartbeat?format=json HTTP/2.0" 200 229 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36 Edg/126.0.0.0"
0 199.204.58.31 - - [28/Jun/2024:13:27:49 -0500] "GET /nextcloud/index.php/apps/logreader/api/poll?lastReqId=OiFb8VC3hfkucstkCzrW HTTP/2.0" 200 556 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36 Edg/126.0.0.0"
20 192.168.1.100 - - [28/Jun/2024:13:27:34 -0500] "MOVE /nextcloud/remote.php/dav/files/chris/Pictures/2024/2024-06/2024_06_20%20IMG_1123.jpg HTTP/1.1" 201 755 "-" "Mozilla/5.0 (Windows) mirall/3.13.0stable-Win64 (build 20240423) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
0 199.204.58.31 - - [28/Jun/2024:13:27:59 -0500] "GET /nextcloud/ocs/v2.php/apps/notifications/api/v2/notifications HTTP/2.0" 304 549 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36 Edg/126.0.0.0"
0 192.168.1.100 - - [28/Jun/2024:13:27:59 -0500] "GET /nextcloud/ocs/v1.php/cloud/user?format=json HTTP/1.1" 200 1391 "-" "Mozilla/5.0 (Windows) mirall/3.13.0stable-Win64 (build 20240423) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"
0 199.204.58.31 - - [28/Jun/2024:13:27:59 -0500] "GET /nextcloud/index.php/apps/logreader/api/poll?lastReqId=OiFb8VC3hfkucstkCzrW HTTP/2.0" 200 103 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36 Edg/126.0.0.0"
0 192.168.1.100 - - [28/Jun/2024:13:27:59 -0500] "GET /nextcloud/remote.php/dav/avatars/chris/128.png HTTP/1.1" 200 2640 "-" "Mozilla/5.0 (Windows) mirall/3.13.0stable-Win64 (build 20240423) (Nextcloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64)"

Note that the timestamps below are not correlated to the slow request response times above. I do not think they are related.

error.log:


[Fri Jun 28 13:23:21.029788 2024] [access_compat:error] [pid 46919:tid 139720814208576] [client 127.0.0.1:33610] AH01797: client denied by server configuration: /var/www/nextcloud/data/.ocdata
[Fri Jun 28 13:23:21.080431 2024] [access_compat:error] [pid 46956:tid 139720285730368] [client 192.168.1.101:53284] AH01797: client denied by server configuration: /var/www/nextcloud/data/.ocdata
[Fri Jun 28 13:23:41.273382 2024] [access_compat:error] [pid 46956:tid 139720277337664] [client 127.0.0.1:40022] AH01797: client denied by server configuration: /var/www/nextcloud/data/.ocdata
[Fri Jun 28 13:25:28.858856 2024] [proxy_fcgi:error] [pid 46919:tid 139721510475328] [client 192.168.1.101:33116] AH01071: Got error 'Primary script unknown'

Output errors in nextcloud.log in /var/www/ or as admin user in top right menu, filtering for errors. Use a pastebin service if necessary.

No errors in the timeframe.
1 Like

Also, I do not think it is a web server or php performance problem per se.

For example, when I browse images in the NC web client and thumbnail generation is triggered, the load spikes, I can see numerous php–fpm processes on top, and thumbnails are generated in somewhat speedy amount of time.

Also disk speed seems fine:

hdparm -Tt /dev/sda
/dev/sda:
 Timing cached reads:   24462 MB in  1.99 seconds = 12290.65 MB/sec
 Timing buffered disk reads:  92 MB in  3.00 seconds =  30.65 MB/sec

For local filesystems, as long as you’re not moving across partitions/volumes, there’s barely any data I/O for a move/rename. If those are slow, as well as uploads/etc maybe there is something going on with your hardware? Can you check your kernel log?

What’s the underlying filesystem?

But as far as Nextcloud goes…

Is the performance similarly slow when you trigger a move at the command line within Nextcloud:

occ files:move ncuser/files/Nextcloud.png ncuser/files/Nextcloud2.png

(obviously swap out the username and filename)

Any External Mounts involved? Encryption? etc?

Are you by chance using the Anti-virus app or anything like that?

May be this: [Bug]: Nextcloud 28.0.0 Error “NotFoundException” · Issue #42343 · nextcloud/server · GitHub

Oh wait, I now see an error (actually 2 of the same) for each command line copy I do:

    "reqId": "2GxALeKKHfsEx6CZ6D1I",
    "level": 3,
    "time": "2024-06-30T11:22:48+00:00",
    "remoteAddr": "",
    "user": "--",
    "app": "no app in context",
    "method": "",
    "url": "--",
    "message": "Exception thrown: OCP\\Files\\NotFoundException",
    "userAgent": "--",
    "version": "29.0.3.4",
    "exception": {
        "Exception": "OCP\\Files\\NotFoundException",
        "Message": "",
        "Code": 0,
        "Trace": [
            {
                "file": "/var/www/nextcloud/lib/private/Files/Node/Node.php",
                "line": 386,
                "function": "getFileInfo",
                "class": "OC\\Files\\Node\\Node",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/apps/files_versions/lib/Listener/FileEventsListener.php",
                "line": 385,
                "function": "getOwner",
                "class": "OC\\Files\\Node\\Node",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/apps/files_versions/lib/Listener/FileEventsListener.php",
                "line": 310,
                "function": "getPathForNode",
                "class": "OCA\\Files_Versions\\Listener\\FileEventsListener",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/apps/files_versions/lib/Listener/FileEventsListener.php",
                "line": 119,
                "function": "rename_hook",
                "class": "OCA\\Files_Versions\\Listener\\FileEventsListener",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/lib/private/EventDispatcher/ServiceEventListener.php",
                "line": 86,
                "function": "handle",
                "class": "OCA\\Files_Versions\\Listener\\FileEventsListener",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/3rdparty/symfony/event-dispatcher/EventDispatcher.php",
                "line": 230,
                "function": "__invoke",
                "class": "OC\\EventDispatcher\\ServiceEventListener",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/3rdparty/symfony/event-dispatcher/EventDispatcher.php",
                "line": 59,
                "function": "callListeners",
                "class": "Symfony\\Component\\EventDispatcher\\EventDispatcher",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/lib/private/EventDispatcher/EventDispatcher.php",
                "line": 86,
                "function": "dispatch",
                "class": "Symfony\\Component\\EventDispatcher\\EventDispatcher",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/lib/private/EventDispatcher/EventDispatcher.php",
                "line": 98,
                "function": "dispatch",
                "class": "OC\\EventDispatcher\\EventDispatcher",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/lib/private/Files/Node/HookConnector.php",
                "line": 188,
                "function": "dispatchTyped",
                "class": "OC\\EventDispatcher\\EventDispatcher",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/lib/private/legacy/OC_Hook.php",
                "line": 105,
                "function": "postRename",
                "class": "OC\\Files\\Node\\HookConnector",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/lib/private/Files/View.php",
                "line": 852,
                "function": "emit",
                "class": "OC_Hook",
                "type": "::"
            },
            {
                "file": "/var/www/nextcloud/lib/private/Files/Node/Node.php",
                "line": 468,
                "function": "rename",
                "class": "OC\\Files\\View",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/apps/files/lib/Command/Move.php",
                "line": 117,
                "function": "move",
                "class": "OC\\Files\\Node\\Node",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/3rdparty/symfony/console/Command/Command.php",
                "line": 298,
                "function": "execute",
                "class": "OCA\\Files\\Command\\Move",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/3rdparty/symfony/console/Application.php",
                "line": 1040,
                "function": "run",
                "class": "Symfony\\Component\\Console\\Command\\Command",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/3rdparty/symfony/console/Application.php",
                "line": 301,
                "function": "doRunCommand",
                "class": "Symfony\\Component\\Console\\Application",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/3rdparty/symfony/console/Application.php",
                "line": 171,
                "function": "doRun",
                "class": "Symfony\\Component\\Console\\Application",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/lib/private/Console/Application.php",
                "line": 213,
                "function": "run",
                "class": "Symfony\\Component\\Console\\Application",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/console.php",
                "line": 102,
                "function": "run",
                "class": "OC\\Console\\Application",
                "type": "->"
            },
            {
                "file": "/var/www/nextcloud/occ",
                "line": 11,
                "args": [
                    "/var/www/nextcloud/console.php"
                ],
                "function": "require_once"
            }
        ],
        "File": "/var/www/nextcloud/lib/private/Files/Node/Node.php",
        "Line": 113,
        "CustomMessage": "Exception thrown: OCP\\Files\\NotFoundException"
    },
    "id": "6681400b839d6"
}```

There is nothing in the kernal log other than expected iptables stuff. I really don’t think the overall system is having a problem. For example, there’s a daily rsnapshot that runs on all 115,000 files and backs up to a sluggish USB drive and that runs in a reasonable amount of time. And like I previously mentioned, thumbnail generation is fairly quick.

File system is ext4.

Interestingly the occ command line file move also takes a long time (10s for this 380k image). Simply copying the same file to /tmp takes 6ms. Moving a file within the NC data directory using “mv” is similarly fast.

/var/www/nextcloud# time sudo -u www-data php occ files:move  chris/files/Pictures/Autoupload/test-image2.png chris/files/Pictures/Screenshots/test-image.png
real    0m10.151s
user    0m0.344s
sys     0m0.065s

No external mounts for NC; no encryption; no anti-virus.

There are a few sql queries slower than 2s (mostly slightly over 2s) but I don’t see any logged when I do the command line file move above.

What’s the history of this installation?

Were files moved around or was it been moved to a different server before? Or anything like that?

You might try a files:scan possibly followed by a files:cleanup and files:repair-tree: Using the occ command — Nextcloud latest Administration Manual latest documentation

I tried the scan / repair and they both worked fine but did not fix the behavior.

As for history, the installation is basically original from maybe 3-4 (?) years ago. I don’t recall. The drive has been swapped but I believe I used dd to mirror it. Ubuntu has been upgraded versions several times. I don’t think I swapped the workstation itself.

There has been lots of screwing around with the networking. Different IP addresses; DHCP and DNS changes; etc. But since NC mounts are all local and the issue occurs locally, I do not think that is related.

I’ve cross posted with github issue here since I think these are the same.

Interestingly I think I have somewhat narrowed down the problem to mysql performance. Some apt upgrade I think removed innodb_flush_log_at_trx_commit=2 from my config. Putting that back made things somewhat faster.

That said, I also think NC is doing too many SQL commands in general.

The image below shows a SQL performance dump of syncing / uploading 105 modified files sorted by # of executions.

The average time for some of these is part of the problem. As you can see there are some .2 - .3 second queries.

But I think the main problem is just SO MANY update/insert statements. No wonder things take so long if 105 file updates create, for example, 225 update oc_filecache statements with an average time of .325 seconds each.

One general thing to check is to run sudo atop and observe for situations where the behavior is happening. I have found that atop tends to be effective for finding the cause of bottlenecks.