[Bug]: file is locked, existing lock on file: exclusive on big files upload

⚠️ This issue respects the following points: ⚠️

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

Bug description

Getting error "zeros_1gb.new.dd" is locked, existing lock on file: exclusive when uploading large files (1Gb+) with browser.

Setup:

• NextCloud 24.0.1 (official docker image).
• PHP is run by static FPM pool.
• Running in kubernetes (official helm chart).
• NextCloud system files (/var/www/html) stored in RWO volume, 10 pods use this volume on one node.
• User files stored in S3-like storage
• File locking set up in Redis (external Redis server).
• filelocking.debug set to true

Logs viewed through Kibana show (pod_name - log_message, notice MOVE request, second lock attempt is done by different pod if it matters):

app-nextcloud-int-6f8b6d568-v9lng - NOTICE: PHP message: [owncloud][locking][1] acquire shared lock on "files/zeros_1gb.new.dd" on storage "object::user:popov.k"
app-nextcloud-int-6f8b6d568-v9lng - NOTICE: PHP message: [owncloud][locking][1] change lock on "files/zeros_1gb.new.dd" to exclusive on storage "object::user:popov.k"
app-nextcloud-int-6f8b6d568-vbdbt - NOTICE: PHP message: [owncloud][locking][1] acquire shared lock on "files/zeros_1gb.new.dd" on storage "object::user:popov.k"
app-nextcloud-int-6f8b6d568-vbdbt - NOTICE: PHP message: [owncloud][no app in context][1] {"Exception":"OCP\\Lock\\LockedException","Message":"\"files/9faf980fca1fefa8ed8a83420b80642b\"(\"object::user:popov.k::files/zeros_1gb.new.dd\") is locked, existing lock on file: exclusive","Code":0,"Trace":[{"file":"/var/www/html/lib/private/Files/Storage/Common.php","line":758,"function":"acquireLock","class":"OC\\Lock\\MemcacheLockingProvider","type":"->","args":["files/9faf980fca1fefa8ed8a83420b80642b",1,"object::user:popov.k::files/zeros_1gb.new.dd"]},{"file":"/var/www/html/lib/private/Files/Storage/Wrapper/Wrapper.php","line":610,"function":"acquireLock","class":"OC\\Files\\Storage\\Common","type":"->","args":["files/zeros_1gb.new.dd",1,{"__class__":"OC\\Lock\\MemcacheLockingProvider"}]},{"file":"/var/www/html/lib/private/Files/Storage/Wrapper/Wrapper.php","line":610,"function":"acquireLock","class":"OC\\Files\\Storage\\Wrapper\\Wrapper","type":"->","args":["files/zeros_1gb.new.dd",1,{"__class__":"OC\\Lock\\MemcacheLockingProvider"}]},{"file":"/var/www/html/lib/private/Files/View.php","line":1961,"function":"acquireLock","class":"OC\\Files\\Storage\\Wrapper\\Wrapper","type":"->","args":["files/zeros_1gb.new.dd",1,{"__class__":"OC\\Lock\\MemcacheLockingProvider"}]},{"file":"/var/www/html/lib/private/Files/View.php","line":2076,"function":"lockPath","class":"OC\\Files\\View","type":"->","args":["//zeros_1gb.new.dd",1,false]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Node.php","line":406,"function":"lockFile","class":"OC\\Files\\View","type":"->","args":["//zeros_1gb.new.dd",1]},{"file":"/var/www/html/apps/dav/lib/Connector/Sabre/Directory.php","line":161,"function":"acquireLock","class":"OCA\\DAV\\Connector\\Sabre\\Node","type":"->","args":[1]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Tree.php","line":307,"function":"createFile","class":"OCA\\DAV\\Connector\\Sabre\\Directory","type":"->","args":["zeros_1gb.new.dd",null]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Tree.php","line":133,"function":"copyNode","class":"Sabre\\DAV\\Tree","type":"->","args":[{"__class__":"OCA\\DAV\\Upload\\FutureFile"},{"__class__":"OCA\\DAV\\Files\\FilesHome"},"zeros_1gb.new.dd"]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Tree.php","line":163,"function":"copy","class":"Sabre\\DAV\\Tree","type":"->","args":["uploads/popov.k/web-file-upload-ec4426fdee1b17f40277ca0514822f4b-1656342757986/.file","files/popov.k/zeros_1gb.new.dd"]},{"file":"/var/www/html/apps/dav/lib/Upload/ChunkingPlugin.php","line":94,"function":"move","class":"Sabre\\DAV\\Tree","type":"->","args":["uploads/popov.k/web-file-upload-ec4426fdee1b17f40277ca0514822f4b-1656342757986/.file","files/popov.k/zeros_1gb.new.dd"]},{"file":"/var/www/html/apps/dav/lib/Upload/ChunkingPlugin.php","line":76,"function":"performMove","class":"OCA\\DAV\\Upload\\ChunkingPlugin","type":"->","args":["uploads/popov.k/web-file-upload-ec4426fdee1b17f40277ca0514822f4b-1656342757986/.file","files/popov.k/zeros_1gb.new.dd"]},{"file":"/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"beforeMove","class":"OCA\\DAV\\Upload\\ChunkingPlugin","type":"->","args":["uploads/popov.k/web-file-upload-ec4426fdee1b17f40277ca0514822f4b-1656342757986/.file","files/popov.k/zeros_1gb.new.dd"]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/CorePlugin.php","line":603,"function":"emit","class":"Sabre\\DAV\\Server","type":"->","args":["beforeMove",["uploads/popov.k/web-file-upload-ec4426fdee1b17f40277ca0514822f4b-1656342757986/.file","files/popov.k/zeros_1gb.new.dd"]]},{"file":"/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"httpMove","class":"Sabre\\DAV\\CorePlugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":472,"function":"emit","class":"Sabre\\DAV\\Server","type":"->","args":["method:MOVE",[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/lib/Server.php","line":352,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/remote.php","line":166,"args":["/var/www/html/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Lock/MemcacheLockingProvider.php","Line":80,"CustomMessage":"--"}
app-nextcloud-int-6f8b6d568-v9lng - NOTICE: PHP message: [owncloud][locking][1] change lock on "files/zeros_1gb.new.dd" to shared on storage "object::user:popov.k"
app-nextcloud-int-6f8b6d568-v9lng - NOTICE: PHP message: [owncloud][locking][1] release shared lock on "files/zeros_1gb.new.dd" on storage "object::user:popov.k"

From browser the process looks like the following:

• file is being uploaded in chunks
• after last chunk is uploaded, request "MOVE /remote.php" is done which completes with 423 (Locked) response. (I suspect this code making the request)
• error message is displayed in NextCloud pop-up
• file remains in NextCloud with .part suffix

When using desktop client to sync the same file server-side logs display the same sequence but the client (probably) does retry for this MOVE request which succeeds.

Steps to reproduce

1. set up NectCloud like described above
2. upload 1Gb+ file via browser

Expected behavior

Even large files uploaded successfully.

Solution (?): Locking retried on server side when executing the MOVE request.

Installation method

Official Docker image

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.0

Web server

Nginx

Database engine version

PostgreSQL

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

Fresh Nextcloud Server install

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

What user-backends are you using?

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

Configuration report

{
    "system": {
        "htaccess.RewriteBase": "\/",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "apps_paths": [
            {
                "path": "\/var\/www\/html\/apps",
                "url": "\/apps",
                "writable": false
            },
            {
                "path": "\/var\/www\/html\/custom_apps",
                "url": "\/custom_apps",
                "writable": true
            }
        ],
        "log_type": "errorlog",
        "loglevel": 1,
        "logfile": "",
        "log_type_audit": "errorlog",
        "maintenance_window_start": 100,
        "overwriteprotocol": "https",
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***",
        "objectstore": {
            "class": "\\OC\\Files\\ObjectStore\\S3",
            "arguments": {
                "bucket": "nextcloud-int-sbmt-infra",
                "autocreate": false,
                "key": "***REMOVED SENSITIVE VALUE***",
                "secret": "***REMOVED SENSITIVE VALUE***",
                "hostname": "storage.yandexcloud.net",
                "region": "ru-central1",
                "use_ssl": true,
                "use_path_style": true
            }
        },
        "mail_smtpmode": "smtp",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "465",
        "mail_smtpsecure": "ssl",
        "mail_smtpauth": false,
        "mail_smtpauthtype": "LOGIN",
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "localhost",
            "nextcloud.sbmt.io",
            "nextcloud"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "pgsql",
        "version": "24.0.1.1",
        "overwrite.cli.url": "https:\/\/localhost",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": "6379",
            "password": "***REMOVED SENSITIVE VALUE***"
        },
        "ldapProviderFactory": "OCA\\User_LDAP\\LDAPProviderFactory",
        "app_install_overwrite": [
            "files_external_gdrive",
            "drawio"
        ],
        "maintenance": false,
        "filelocking.debug": {
            "true": "",
            "1": "",
            "false": ""
        }
    }
}

List of activated Apps

Enabled:
  - activity: 2.16.0
  - bruteforcesettings: 2.4.0
  - circles: 24.0.0
  - cloud_federation_api: 1.7.0
  - comments: 1.14.0
  - contacts: 4.1.1
  - contactsinteraction: 1.5.0
  - dashboard: 7.4.0
  - dav: 1.22.0
  - drawio: 1.0.3
  - federatedfilesharing: 1.14.0
  - federation: 1.14.0
  - files: 1.19.0
  - files_external: 1.16.1
  - files_pdfviewer: 2.5.0
  - files_rightclick: 1.3.0
  - files_sharing: 1.16.2
  - files_trashbin: 1.14.0
  - files_versions: 1.17.0
  - files_videoplayer: 1.13.0
  - forms: 2.5.1
  - groupfolders: 12.0.1
  - integration_dropbox: 1.0.4
  - integration_google: 1.0.6
  - lookup_server_connector: 1.12.0
  - nextcloud_announcements: 1.13.0
  - notifications: 2.12.0
  - oauth2: 1.12.0
  - officeonline: 1.1.3
  - password_policy: 1.14.0
  - photos: 1.6.0
  - privacy: 1.8.0
  - provisioning_api: 1.14.0
  - serverinfo: 1.14.0
  - settings: 1.6.0
  - sharebymail: 1.14.0
  - systemtags: 1.14.0
  - text: 3.5.1
  - theming: 1.15.0
  - theming_customcss: 1.11.0
  - twofactor_backupcodes: 1.13.0
  - updatenotification: 1.14.0
  - user_ldap: 1.14.1
  - user_status: 1.4.0
  - viewer: 1.8.0
  - workflowengine: 2.6.0
Disabled:
  - accessibility: 1.8.0
  - admin_audit
  - encryption
  - firstrunwizard: 2.11.0
  - logreader: 2.7.0
  - recommendations: 1.2.0
  - support: 1.6.0
  - survey_client: 1.10.0
  - weather_status: 1.2.0

Nextcloud Signing status

No response

Nextcloud Logs

No response

Additional info

No response

Start with apps/dav/lib/Upload/ChunkingPlugin.php and the MOVE request described in the report, then trace locking through lib/private/Lock/MemcacheLockingProvider.php. Check the browser upload path referenced in apps/files/js/file-upload.js and reproduce with a large file using the reported Redis-backed locking setup. Done means the browser upload completes without a 423 response and the file is not left with a .part suffix.