[Bug]: Upload into group folder causes a massive delay on move operation

[cfiehe]

⚠️ This issue respects the following points: ⚠️

• [X] This is a bug, not a question or a configuration/webserver/proxy issue.
• [X] This issue is not already reported on Github OR Nextcloud Community Forum (I've searched it).
• [X] Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
• [X] I agree to follow Nextcloud's Code of Conduct.

Bug description

We use an S3 object store as primary storage for our Nextcloud cluster. We have recognized that uploads into a group folder cause a massive delay on the final file’s move operation, when the chunks are being assembled and the file gets created on the actual upload target:

Uploads of a 6 GB file cause a delay of 2.14 min and a 170 GB file a delay of 33 min.

When the upload appears outside of a group folder, the move operation does not cause any noticeable delay. During a normal upload the command sequence ends with a CompleteMultipartUpload. In case of group folder target, a lot of additional CopyObjectPart commands are being created and sent to the object storage. It depends on the file size, and the number of chunks, when the sequence ends.

I have attached a trace (refer to: Additional info) on a test bucket on our MinIO-S3-storage, which shows, what is actually happening. It looks like a copy-delete sequence initiated by the Nextcloud. Maybe the server thinks, that source and target are located on different storage systems.

Steps to reproduce

1. Create a group folder.
2. Upload a large file into this group folder.
3. Wait until the move operation ends.

Expected behavior

Uploads into a group folder should not cause any noticeable delay on the final move operation.

Nextcloud Server version

28

Operating system

None

PHP engine version

None

Web server

None

Database engine version

None

Is this bug present after an update or on a fresh install?

None

Are you using the Nextcloud Server Encryption module?

None

What user-backends are you using?

• [ ] Default user-backend (database)
• [ ] LDAP/ Active Directory
• [ ] SSO - SAML
• [ ] Other

Configuration report

{
    "system": {
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "nextcloud-s3-t.mycompany.de"
        ],
        "proxy": "proxy.mycompany.de:3128",
        "proxyexclude": [
            "127.0.0.0\/8",
            "localhost",
            ".mycompany.de"
        ],
        "objectstore": {
            "class": "\\OC\\Files\\ObjectStore\\S3",
            "arguments": {
                "bucket": "ed-nxtcld-test",
                "verify_bucket_exists": false,
                "key": "***REMOVED SENSITIVE VALUE***",
                "secret": "***REMOVED SENSITIVE VALUE***",
                "hostname": "nextcloud-minio-srv1-t.lx.mycompany.de",
                "port": 9000,
                "use_ssl": false,
                "use_path_style": true,
                "proxy": false
            }
        },
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "pgsql",
        "version": "29.0.6.1",
        "overwrite.cli.url": "https:\/\/nextcloud-s3-t.mycompany.de",
        "overwriteprotocol": "https",
        "overwritehost": "nextcloud-s3-t.mycompany.de",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "remember_login_cookie_lifetime": 1296000,
        "session_lifetime": 86400,
        "session_keepalive": true,
        "auto_logout": true,
        "mail_smtpmode": "sendmail",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": 25,
        "mail_sendmailmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "default_locale": "de_DE",
        "default_phone_region": "DE",
        "filelocking.enabled": true,
        "htaccess.RewriteBase": "\/",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 6379,
            "user": "default"
        },
        "theme": "",
        "loglevel": 2,
        "maintenance": false,
        "maintenance_window_start": 1,
        "ldapProviderFactory": "\\OCA\\User_LDAP\\LDAPProviderFactory",
        "updater.release.channel": "stable"
    }
}

List of activated Apps

Enabled:
  - activity: 2.21.1
  - circles: 29.0.0-dev
  - cloud_federation_api: 1.12.0
  - comments: 1.19.0
  - contactsinteraction: 1.10.0
  - dashboard: 7.9.0
  - dav: 1.30.1
  - federatedfilesharing: 1.19.0
  - federation: 1.19.0
  - files: 2.1.1
  - files_downloadlimit: 2.0.0
  - files_pdfviewer: 2.10.0
  - files_reminders: 1.2.0
  - files_sharing: 1.21.0
  - files_trashbin: 1.19.0
  - files_versions: 1.22.0
  - firstrunwizard: 2.18.0
  - groupfolders: 17.0.3
  - logreader: 2.14.0
  - lookup_server_connector: 1.17.0
  - nextcloud_announcements: 1.18.0
  - notifications: 2.17.0
  - oauth2: 1.17.0
  - password_policy: 1.19.0
  - photos: 2.5.0
  - privacy: 1.13.0
  - provisioning_api: 1.19.0
  - recommendations: 2.1.0
  - related_resources: 1.4.0
  - serverinfo: 1.19.0
  - settings: 1.12.0
  - sharebymail: 1.19.0
  - support: 1.12.0
  - survey_client: 1.17.0
  - systemtags: 1.19.0
  - text: 3.10.1
  - theming: 2.4.0
  - twofactor_backupcodes: 1.18.0
  - updatenotification: 1.19.1
  - user_status: 1.9.0
  - viewer: 2.3.0
  - weather_status: 1.9.0
  - workflowengine: 2.11.0
Disabled:
  - admin_audit: 1.19.0
  - bruteforcesettings: 2.9.0
  - encryption: 2.17.0
  - files_external: 1.21.0
  - suspicious_login: 7.0.0
  - twofactor_totp: 11.0.0-dev
  - user_ldap: 1.20.0

Nextcloud Signing status

No errors have been found.

Nextcloud Logs

No response

Additional info

minio-groupfolder-trace.txt

[cfiehe]

I can provide the stacktrace from an upload to a group folder. It really looks like the Nextcloud thinks that it must move the file to a different storage via a copy-delete sequence:

[10-Sep-2024 08:58:35]  [pool nextcloud] pid 173903
script_filename = /var/www/html/nextcloud/remote.php
[0x00007373e3c15a00] dispatch() /var/www/html/nextcloud/3rdparty/mtdowling/jmespath.php/src/TreeInterpreter.php:56
[0x00007373e3c15870] dispatch() /var/www/html/nextcloud/3rdparty/mtdowling/jmespath.php/src/TreeInterpreter.php:32
[0x00007373e3c157f0] visit() /var/www/html/nextcloud/3rdparty/mtdowling/jmespath.php/src/AstRuntime.php:45
[0x00007373e3c15760] __invoke() /var/www/html/nextcloud/3rdparty/mtdowling/jmespath.php/src/Env.php:33
[0x00007373e3c156d0] search() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/Endpoint/PartitionEndpointProvider.php:117
[0x00007373e3c15590] mergePrefixData() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/Endpoint/PartitionEndpointProvider.php:99
[0x00007373e3c154e0] defaultProvider() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/S3/S3EndpointMiddleware.php:86
[0x00007373e3c15430] __construct() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/S3/S3EndpointMiddleware.php:66
[0x00007373e3c15390] Aws\S3\{closure}() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/HandlerList.php:302
[0x00007373e3c15300] resolve() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/AwsClientTrait.php:63
[0x00007373e3c15280] executeAsync() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/CommandPool.php:67
[0x00007373dd04de00] Aws\{closure}() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/EachPromise.php:205
[0x00007373e3c15230] next() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/EachPromise.php:205
[0x00007373e3c151c0] advanceIterator() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/EachPromise.php:231
[0x00007373e3c15150] step() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/EachPromise.php:176
[0x00007373e3c150b0] GuzzleHttp\Promise\{closure}() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:204
[0x00007373e3c14f80] callHandler() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:153
[0x00007373e3c14ee0] GuzzleHttp\Promise\{closure}() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/TaskQueue.php:48
[0x00007373e3c14e70] run() /var/www/html/nextcloud/3rdparty/guzzlehttp/guzzle/src/Handler/CurlMultiHandler.php:163
[0x00007373e3c14dc0] tick() /var/www/html/nextcloud/3rdparty/guzzlehttp/guzzle/src/Handler/CurlMultiHandler.php:189
[0x00007373e3c14d40] execute() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:248
[0x00007373e3c14ca0] invokeWaitFn() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:224
[0x00007373e3c14c20] waitIfPending() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:269
[0x00007373e3c14b90] invokeWaitList() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:226
[0x00007373e3c14b10] waitIfPending() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:269
[0x00007373e3c14a80] invokeWaitList() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:226
[0x00007373e3c14a00] waitIfPending() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:62
[0x00007373e3c14970] wait() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Coroutine.php:67
[0x00007373e3c148f0] GuzzleHttp\Promise\{closure}() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:248
[0x00007373e3c14850] invokeWaitFn() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:224
[0x00007373e3c147d0] waitIfPending() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:269
[0x00007373e3c14740] invokeWaitList() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:226
[0x00007373e3c146c0] waitIfPending() /var/www/html/nextcloud/3rdparty/guzzlehttp/promises/src/Promise.php:62
[0x00007373e3c14630] wait() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/Multipart/AbstractUploadManager.php:83
[0x00007373e3c145d0] upload() /var/www/html/nextcloud/3rdparty/aws/aws-sdk-php/src/S3/MultipartCopy.php:86
[0x00007373e3c14570] copy() /var/www/html/nextcloud/lib/private/Files/ObjectStore/S3ObjectTrait.php:215
[0x00007373e3c14470] copyObject() /var/www/html/nextcloud/lib/private/Files/ObjectStore/ObjectStoreStorage.php:666
[0x00007373e3c14390] copyFile() /var/www/html/nextcloud/lib/private/Files/ObjectStore/ObjectStoreStorage.php:648
[0x00007373e3c142b0] copyInner() /var/www/html/nextcloud/lib/private/Files/ObjectStore/ObjectStoreStorage.php:612
[0x00007373e3c141d0] copyFromStorage() /var/www/html/nextcloud/lib/private/Files/Storage/Common.php:705
[0x00007373e3c14130] moveFromStorage() /var/www/html/nextcloud/lib/private/Files/Storage/Wrapper/Wrapper.php:601
[0x00007373e3c14090] moveFromStorage() /var/www/html/nextcloud/apps/files_trashbin/lib/Storage.php:235
[0x00007373e3c13fd0] moveFromStorage() /var/www/html/nextcloud/lib/private/Files/Storage/Wrapper/Jail.php:501
[0x00007373e3c13f30] moveFromStorage() /var/www/html/nextcloud/lib/private/Files/Storage/Wrapper/Quota.php:240
[0x00007373e3c13e80] moveFromStorage() /var/www/html/nextcloud/lib/private/Files/Storage/Wrapper/Wrapper.php:601
[0x00007373e3c13de0] moveFromStorage() /var/www/html/nextcloud/lib/private/Files/Storage/Wrapper/Wrapper.php:601
[0x00007373e3c13d40] moveFromStorage() /var/www/html/nextcloud/apps/files_trashbin/lib/Storage.php:235
[0x00007373e3c13c80] moveFromStorage() /var/www/html/nextcloud/lib/private/Files/View.php:820
[0x00007373e3c13aa0] rename() /var/www/html/nextcloud/lib/private/Files/Node/Node.php:468
[0x00007373e3c139c0] move() /var/www/html/nextcloud/apps/dav/lib/Upload/ChunkingV2Plugin.php:353
[0x00007373e3c138d0] completeChunkedWrite() /var/www/html/nextcloud/apps/dav/lib/Upload/ChunkingV2Plugin.php:238
[0x00007373e3c136f0] beforeMove() /var/www/html/nextcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php:89
[0x00007373e3c13610] emit() /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/CorePlugin.php:603
[0x00007373e3c13540] httpMove() /var/www/html/nextcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php:89
[0x00007373e3c13460] emit() /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php:472
[0x00007373e3c133a0] invokeMethod() /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php:253
[0x00007373e3c132a0] start() /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php:321
[0x00007373e3c13250] exec() /var/www/html/nextcloud/apps/dav/lib/Server.php:385
[0x00007373e3c131d0] exec() /var/www/html/nextcloud/apps/dav/appinfo/v2/remote.php:35
[0x00007373e3c13140] [INCLUDE_OR_EVAL]() /var/www/html/nextcloud/remote.php:172

[cfiehe]

I am not sure and hope, that the issue can be fixed directly in the groupfolders plugin: https://github.com/nextcloud/groupfolders/pull/3205

[sorbaugh]

Fixed by https://github.com/nextcloud/server/pull/47986 💪