Server: OCA\DAV\Connector\Sabre\Exception\FileLocked - Redis race condition

[asengineeringsupport]

Steps to reproduce

1. Install and configure Redis
2. Upload a bigger file for longer than 1 hour.

Expected behaviour

When the upload finishes (monitoring the last seconds) the file should appear on filesystem and in webinterface.

Actual behaviour

The last Bytes are transmitting and then appears the "locked" message in Webbrower. The message
OCA\DAV\Connector\Sabre\Exception\FileLocked will be logged in Adminpage. It happens when somebody uses a not so fast Internetconnection and is uploading for longer than one hour (f.e. 3GB, over 5 MBit/s, over 70-80 minutes), but somebody who is able to upload 4.5 GB in 12 minutes has success.

Server configuration

Operating system: Ubuntu 16.04.4 LTS

Web server: apache2 (2.4.18-2ubuntu3.5)

Database:

PHP version: php7.0 7.0.28-0ubuntu0.16.04.1 [1.290 B]

Nextcloud version: 12.0.3, 12.0.6 (actually), 13.0.0

Updated from an older Nextcloud/ownCloud or fresh install: First 12.0.3 than updated over Adminpage.

Where did you install Nextcloud from: Ubuntu repository

Signing status:

Signing status

Fatal webdav OCA\DAV\Connector\Sabre\Exception\FileLocked: "xxxx_GmbH/to_xxx_xxx/Autocad 2010.nrg" is locked0./var/www/html/nextcloud/apps/dav/lib/Connector/Sabre/Directory.php - line 151:  OCA\DAV\Connector\Sabre\File->put(Resource id #20)
1./var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php - line 1096:  OCA\DAV\Connector\Sabre\Directory->createFile('Autocad 2010.nr...', Resource id #20)
2./var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/CorePlugin.php - line 525:  Sabre\DAV\Server->createFile('xxxx_GmbH/to_xx...', Resource id #20, NULL)
3.[internal function] Sabre\DAV\CorePlugin->httpPut(Object(Sabre\HTTP\Request), Object(Sabre\HTTP\Response))
4./var/www/html/nextcloud/3rdparty/sabre/event/lib/EventEmitterTrait.php - line 105:  call_user_func_array(Array, Array)
5./var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php - line 479:  Sabre\Event\EventEmitter->emit('method PUT', Array)
6./var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php - line 254:  Sabre\DAV\Server->invokeMethod(Object(Sabre\HTTP\Request), Object(Sabre\HTTP\Response))
7./var/www/html/nextcloud/apps/dav/appinfo/v1/webdav.php - line 76:  Sabre\DAV\Server->exec()
8./var/www/html/nextcloud/remote.php - line 164:  require_once('/var/www/html/n...')
9.{main}

List of activated apps:

App list

Enabled:
  - activity: 2.5.2
  - admin_audit: 1.2.0
  - bruteforcesettings: 1.0.3
  - checksum: 0.3.5
  - comments: 1.2.0
  - dav: 1.3.1
  - federatedfilesharing: 1.2.0
  - federation: 1.2.0
  - files: 1.7.2
  - files_accesscontrol: 1.2.5
  - files_pdfviewer: 1.1.1
  - files_sharing: 1.4.0
  - files_texteditor: 2.4.1
  - files_trashbin: 1.2.0
  - files_versions: 1.5.0
  - files_videoplayer: 1.1.0
  - firstrunwizard: 2.1
  - gallery: 17.0.0
  - groupfolders: 1.2.0
  - logreader: 2.0.0
  - lookup_server_connector: 1.0.0
  - nextcloud_announcements: 1.1
  - notifications: 2.0.0
  - oauth2: 1.0.5
  - password_policy: 1.2.2
  - provisioning_api: 1.2.0
  - quota_warning: 1.1.1
  - serverinfo: 1.2.0
  - sharebymail: 1.2.0
  - survey_client: 1.0.0
  - systemtags: 1.2.0
  - theming: 1.3.0
  - twofactor_backupcodes: 1.1.1
  - updatenotification: 1.2.0
  - user_ldap: 1.2.1
  - workflowengine: 1.2.0
Disabled:
  - encryption
  - files_external
  - user_external

Nextcloud configuration:

Config report

<?php
$CONFIG = array (
  'instanceid' => 'xxxxxxxxxxxx',
  'passwordsalt' => 'xxxxxxxxxxxxxxx',
  'secret' => 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx',
  'trusted_domains' =>
  array (
    0 => '192.168.10.33',
    1 => 'cloud.xxxxxx.de',
  ),
  'datadirectory' => '/store/nextcloud-data',
  'overwrite.cli.url' => 'http://192.168.10.33/nextcloud',
  'dbtype' => 'mysql',
  'version' => '12.0.6.1',
  'dbname' => 'nextcloud',
  'dbhost' => 'localhost',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'dbuser' => 'xxxxxxxxxxx',
  'dbpassword' => 'xxxxxxxxxxx',
  'installed' => true,
  'filelocking.enabled' => true,
  'memcache.distributed' => '\\OC\\Memcache\\Redis',
  'memcache.local' => '\\OC\\Memcache\\Redis',
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'redis' =>
  array (
    'host' => 'localhost',
    'port' => 6379,
  ),
  'mail_from_address' => 'xxxxxxx',
  'mail_smtpmode' => 'smtp',
  'mail_smtpauthtype' => 'LOGIN',
  'mail_domain' => xxxxxxxxxxx.de',
  'mail_smtphost' => xxxxxxxxxx.xxx.local',
  'mail_smtpport' => '25',
  'updater.release.channel' => 'stable',
  'maintenance' => false,
  'ldapIgnoreNamingRules' => false,
  'ldapProviderFactory' => '\\OCA\\User_LDAP\\LDAPProviderFactory',
  'updater.secret' => 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
  'theme' => '',
  'loglevel' => 2,
);

Are you using external storage, if yes which one: Yes, SMB.

Are you using encryption: No internal/build-in. Only encrypted filesystem on Ubuntu-erver himself and Bitlocker on Fileserver.

Are you using an external user-backend, if yes which one: No

Client configuration

Browser: Internet Explorer 11, Firefox 59.0.2

Operating system: Windows 7 Professional x64

Logs

Web server error log

Web server error log

[Mon Mar 26 06:25:02.314662 2018] [mpm_prefork:notice] [pid 21244] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Mon Mar 26 06:25:02.314757 2018] [core:notice] [pid 21244] AH00094: Command line: '/usr/sbin/apache2'
[Mon Mar 26 14:01:03.162471 2018] [mpm_prefork:notice] [pid 21244] AH00171: Graceful restart requested, doing restart
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.1.1. Set the 'ServerName' directive globally to suppress this message
[Mon Mar 26 14:01:03.218000 2018] [mpm_prefork:notice] [pid 21244] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Mon Mar 26 14:01:03.218012 2018] [core:notice] [pid 21244] AH00094: Command line: '/usr/sbin/apache2'
[Mon Mar 26 21:25:11.241890 2018] [mpm_prefork:notice] [pid 21244] AH00169: caught SIGTERM, shutting down
[Mon Mar 26 21:25:12.308033 2018] [mpm_prefork:notice] [pid 46408] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Mon Mar 26 21:25:12.308074 2018] [core:notice] [pid 46408] AH00094: Command line: '/usr/sbin/apache2'
[Mon Mar 26 21:25:53.944791 2018] [mpm_prefork:notice] [pid 46408] AH00169: caught SIGTERM, shutting down
[Mon Mar 26 21:26:27.243619 2018] [mpm_prefork:notice] [pid 1409] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Mon Mar 26 21:26:27.245690 2018] [core:notice] [pid 1409] AH00094: Command line: '/usr/sbin/apache2'
[Mon Mar 26 21:33:40.697760 2018] [mpm_prefork:notice] [pid 1409] AH00169: caught SIGTERM, shutting down
[Mon Mar 26 21:33:41.764078 2018] [mpm_prefork:notice] [pid 2270] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Mon Mar 26 21:33:41.764121 2018] [core:notice] [pid 2270] AH00094: Command line: '/usr/sbin/apache2'
[Mon Mar 26 23:00:18.538636 2018] [mpm_prefork:notice] [pid 2270] AH00169: caught SIGTERM, shutting down
[Mon Mar 26 23:00:19.857040 2018] [mpm_prefork:notice] [pid 2815] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Mon Mar 26 23:00:19.857088 2018] [core:notice] [pid 2815] AH00094: Command line: '/usr/sbin/apache2'
[Tue Mar 27 02:01:03.232558 2018] [mpm_prefork:notice] [pid 2815] AH00171: Graceful restart requested, doing restart
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.1.1. Set the 'ServerName' directive globally to suppress this message
[Tue Mar 27 02:01:03.297159 2018] [mpm_prefork:notice] [pid 2815] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Tue Mar 27 02:01:03.297171 2018] [core:notice] [pid 2815] AH00094: Command line: '/usr/sbin/apache2'
[Tue Mar 27 06:25:02.552259 2018] [mpm_prefork:notice] [pid 2815] AH00171: Graceful restart requested, doing restart
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.1.1. Set the 'ServerName' directive globally to suppress this message
[Tue Mar 27 06:25:02.590111 2018] [mpm_prefork:notice] [pid 2815] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Tue Mar 27 06:25:02.590120 2018] [core:notice] [pid 2815] AH00094: Command line: '/usr/sbin/apache2'
[Tue Mar 27 06:25:02.827004 2018] [mpm_prefork:notice] [pid 2815] AH00171: Graceful restart requested, doing restart
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.1.1. Set the 'ServerName' directive globally to suppress this message

Nextcloud log (data/nextcloud.log)

Nextcloud log

Don't know where to fing the nextcloud.log. /var/www/html/nextcloud/data/nextcloud.log is empty.

[BurtGummer]

I have the same problem with 2 servers on Debian 9.

[arduino43]

Exact same problem here as well.

[ZoeED]

I have had the same problem as well. We have remote offices uploading over 5mbps lines and after several attempts to upload 1/2GB files we had to give up.

We have stopped using NextCloud and will have to wait until this is fixed.

[Proton23]

Same here.
I can synchronise folders with a file > 3GB without a problem, but if I try to sync a folder which contains 2 files of that size it takes more than hour with my connection and than I get the exact behaviour as described above. max_execution_time set to 10800 but without any changes.

[leog23]

Same problem. Large files over a slow link cause file locking - the same upload over a fast network will successfully upload.

I would love a fix for this.

[krocheck]

We have started experiencing this more than in the past ... I can't prove correlation to the upgrade from 12 to 13, but that's what it feels like.

[BurtGummer]

Hello,

one more example. As described here

https://docs.nextcloud.com/server/12/user_manual/files/access_webdav.html#accessing-files-using-curl

i use curl to upload a 4,4GB file. The first from a Hetzner root-server with 100MB/s connection:

root@Server ~ # time curl -u MY-USER:aaaaa-bbbbb-ccccc-ddddd-eeeee -T KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso https://example.org/cloud/remote.php/dav/files/MY-USER/nichtDownload/upload/

real    2m16,990s
user    0m6,608s
sys     0m4,644s
root@Server ~ # ls -alh KNO*
-rw-r--r-- 1 root root 4,4G Apr  3 13:48 KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso
root@Server ~ #

The second with a 2MB/s upload cable-connection:

root@nas:~$ time curl -u MY-USER:aaaaa-bbbbb-ccccc-ddddd-eeeee -T KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso https://example.org/cloud/remote.php/dav/files/MY-USER/nichtDownload/upload/
<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>OCA\DAV\Connector\Sabre\Exception\FileLocked</s:exception>
  <s:message>"nichtDownload/upload/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso" is locked</s:message>
</d:error>

real    298m56,539s
user    1m44,292s
sys     1m11,464s
root@nas:~$ ls -alh KNO*
-rw-rw-rw- 1 root root 4,4G Apr  3 14:18 KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso
root@nas:~$

The complete error from nextcloud.log:

{"reqId":"o31GrPOYQkX8ApRievH2","level":3,"time":"2018-04-12T10:51:50+00:00","remoteAddr":"89.xxx.xxx.xxx","user":"MY-USER","app":"no app in context","method":"PUT","url":"\/cloud\/remote.php\/dav\/files\/MY-USER\/nichtDownload\/upload\/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso","message":"Exception: {\"Exception\":\"OCP\\\\Lock\\\\LockedException\",\"Message\":\"\\\"files\\\/6875118f810d0d4a272d4e6b662cba2e\\\" is locked\",\"Code\":0,\"Trace\":\"#0 \\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Common.php(773): OC\\\\Lock\\\\MemcacheLockingProvider->changeLock('files\\\/6875118f8...', 2)\\n#1 \\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Common->changeLock('files\\\/nichtDown...', 2, Object(OC\\\\Lock\\\\MemcacheLockingProvider))\\n#2 \\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/nichtDown...', 2, Object(OC\\\\Lock\\\\MemcacheLockingProvider))\\n#3 \\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/View.php(1967): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/nichtDown...', 2, Object(OC\\\\Lock\\\\MemcacheLockingProvider))\\n#4 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Node.php(356): OC\\\\Files\\\\View->changeLock('\\\/nichtDownload\\\/...', 2)\\n#5 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php(196): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Node->changeLock(2)\\n#6 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1130): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id #9)\\n#7 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(513): Sabre\\\\DAV\\\\Server->updateFile('files\\\/MY-USER\\\/ni...', Resource id #9, NULL)\\n#8 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#9 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#10 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#11 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#12 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Server.php(283): Sabre\\\\DAV\\\\Server->exec()\\n#13 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(35): OCA\\\\DAV\\\\Server->exec()\\n#14 \\\/var\\\/www\\\/html\\\/nextcloud\\\/remote.php(164): require_once('\\\/var\\\/www\\\/html\\\/n...')\\n#15 {main}\",\"File\":\"\\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/Lock\\\/MemcacheLockingProvider.php\",\"Line\":122}","userAgent":"curl\/7.52.1","version":"13.0.1.1"}
{"reqId":"o31GrPOYQkX8ApRievH2","level":4,"time":"2018-04-12T10:51:50+00:00","remoteAddr":"89.xxx.xxx.xxx","user":"MY-USER","app":"webdav","method":"PUT","url":"\/cloud\/remote.php\/dav\/files\/MY-USER\/nichtDownload\/upload\/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso","message":"Exception: {\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Message\":\"\\\"nichtDownload\\\/upload\\\/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso\\\" is locked\",\"Code\":0,\"Trace\":\"#0 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1130): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id #9)\\n#1 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(513): Sabre\\\\DAV\\\\Server->updateFile('files\\\/MY-USER\\\/ni...', Resource id #9, NULL)\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#5 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Server.php(283): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(35): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/var\\\/www\\\/html\\\/nextcloud\\\/remote.php(164): require_once('\\\/var\\\/www\\\/html\\\/n...')\\n#9 {main}\",\"File\":\"\\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php\",\"Line\":201}","userAgent":"curl\/7.52.1","version":"13.0.1.1"}

My config:

root@Server /var/www/html/nextcloud # sudo -u www-data php occ config:list system
{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "oc.example.org",
            "example.org"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "overwrite.cli.url": "https:\/\/example.org\/cloud",
        "dbtype": "mysql",
        "version": "13.0.1.1",
        "installed": true,
        "theme": "",
        "maintenance": false,
        "secret": "***REMOVED SENSITIVE VALUE***",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "php",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "loglevel": 2,
        "trashbin_retention_obligation": "auto",
        "updatechecker": true,
        "htaccess.RewriteBase": "\/cloud",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "filelocking.debug": true,
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "updater.release.channel": "stable",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 6379,
            "timeout": 0
        }
    }
}
root@Server /var/www/html/nextcloud #

If any informations missing, please ask.

I hope, someone can help. This problem is so frustrating.

[leog23]

It is very frustrating...

[asengineeringsupport]

Same issue after manual 13.0.1 upgrade.

[BurtGummer]

Because of this problem I had to install vsftpd today :-( (and I thought with nextcloud I'd never have to do that again).
And because this report is almost a month old, here is another example, this time with "'loglevel' => 0,":

root@server /var/www/html/nextcloud/data/MY-USER/files/nichtDownload/upload # ls -alh
insgesamt 4,4G
drwxr-x---  3 www-data www-data 4,0K Apr 24 06:14 .
drwxr-xr-x 17 www-data www-data 4,0K Mär 28 11:38 ..
-rw-r--r--  1 www-data www-data 4,4G Apr 24 11:12 KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso.ocTransferId1472831112.part
root@server /var/www/html/nextcloud/data/MY-USER/files/nichtDownload/upload #

some seconds later:

root@nas:~$ time curl -u MY-USER:aaaaa-bbbbb-cccccc-dddd -T KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso https://example.org/cloud/remote.php/dav/files/MY-USER/nichtDownload/upload/
<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>OCA\DAV\Connector\Sabre\Exception\FileLocked</s:exception>
  <s:message>"nichtDownload/upload/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso" is locked</s:message>
</d:error>

real    299m30,041s
user    1m44,700s
sys     1m8,352s
root@nas:~$

And the nextcloud.log:

{"reqId":"eBRCIZL7yZJstOPj8Qxn","level":1,"time":"2018-04-24T09:13:04+00:00","remoteAddr":"xx.xxx.xxx.140","user":"MY-USER","app":"locking","method":"PUT","url":"\/cloud\/remote.php\/dav\/files\/MY-USER\/nichtDownload\/upload\/KN
OPPIX_V7.7.1DVD-2016-10-22-DE.iso","message":"release shared lock on \"files\/nichtDownload\/upload\" on storage \"home::MY-USER\"","userAgent":"curl\/7.52.1","version":"13.0.1.1"}
{"reqId":"eBRCIZL7yZJstOPj8Qxn","level":1,"time":"2018-04-24T09:13:04+00:00","remoteAddr":"xx.xxx.xxx.140","user":"MY-USER","app":"locking","method":"PUT","url":"\/cloud\/remote.php\/dav\/files\/MY-USER\/nichtDownload\/upload\/KN
OPPIX_V7.7.1DVD-2016-10-22-DE.iso","message":"change lock on \"files\/nichtDownload\/upload\/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso\" to exclusive on storage \"home::MY-USER\"","userAgent":"curl\/7.52.1","version":"13.0.1.1"}
{"reqId":"eBRCIZL7yZJstOPj8Qxn","level":3,"time":"2018-04-24T09:13:04+00:00","remoteAddr":"xx.xxx.xxx.140","user":"MY-USER","app":"no app in context","method":"PUT","url":"\/cloud\/remote.php\/dav\/files\/MY-USER\/nichtDownload\/
upload\/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso","message":"Exception: {\"Exception\":\"OCP\\\\Lock\\\\LockedException\",\"Message\":\"\\\"files\\\/6875118f810d0d4a272d4e6b662cba2e\\\" is locked\",\"Code\":0,\"Trace\":\"#0 \\\/var\
\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Common.php(773): OC\\\\Lock\\\\MemcacheLockingProvider->changeLock('files\\\/6875118f8...', 2)\\n#1 \\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/F
iles\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Common->changeLock('files\\\/nichtDown...', 2, Object(OC\\\\Lock\\\\MemcacheLockingProvider))\\n#2 \\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\
\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/nichtDown...', 2, Object(OC\\\\Lock\\\\MemcacheLockingProvider))\\n#3 \\\/var\\\/www\\\/html\\\/nextcloud\\\
/lib\\\/private\\\/Files\\\/View.php(1967): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/nichtDown...', 2, Object(OC\\\\Lock\\\\MemcacheLockingProvider))\\n#4 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\
/dav\\\/lib\\\/Connector\\\/Sabre\\\/Node.php(356): OC\\\\Files\\\\View->changeLock('\\\/nichtDownload\\\/...', 2)\\n#5 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php(196): OCA\\\\DA
V\\\\Connector\\\\Sabre\\\\Node->changeLock(2)\\n#6 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php(151): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id #9)\\n#7 \\\/v
ar\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1096): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('KNOPPIX_V7.7.1D...', Resource id #9)\\n#8 \\\/var\\\/www\\\/html\\\/nextcl
oud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(525): Sabre\\\\DAV\\\\Server->createFile('files\\\/MY-USER\\\/ni...', Resource id #9, NULL)\\n#9 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sab
re\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#10 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#11 \\\/var\\\/www\\\
/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#12 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/S
erver.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#13 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Server.php(283): Sabre\\\\DAV\\\\Serve
r->exec()\\n#14 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(35): OCA\\\\DAV\\\\Server->exec()\\n#15 \\\/var\\\/www\\\/html\\\/nextcloud\\\/remote.php(164): require_once('\\\/var\\\/www\\\/h
tml\\\/n...')\\n#16 {main}\",\"File\":\"\\\/var\\\/www\\\/html\\\/nextcloud\\\/lib\\\/private\\\/Lock\\\/MemcacheLockingProvider.php\",\"Line\":122}","userAgent":"curl\/7.52.1","version":"13.0.1.1"}
{"reqId":"eBRCIZL7yZJstOPj8Qxn","level":4,"time":"2018-04-24T09:13:04+00:00","remoteAddr":"xx.xxx.xxx.140","user":"MY-USER","app":"webdav","method":"PUT","url":"\/cloud\/remote.php\/dav\/files\/MY-USER\/nichtDownload\/upload\/KNO
PPIX_V7.7.1DVD-2016-10-22-DE.iso","message":"Exception: {\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Message\":\"\\\"nichtDownload\\\/upload\\\/KNOPPIX_V7.7.1DVD-2016-10-22-DE.iso\\\" is lock
ed\",\"Code\":0,\"Trace\":\"#0 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php(151): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id #9)\\n#1 \\\/var\\\/www\\\/html\\\/
nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1096): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('KNOPPIX_V7.7.1D...', Resource id #9)\\n#2 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sa
bre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(525): Sabre\\\\DAV\\\\Server->createFile('files\\\/MY-USER\\\/ni...', Resource id #9, NULL)\\n#3 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request
), Object(Sabre\\\\HTTP\\\\Response))\\n#4 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#5 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3
rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#6 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\
\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#7 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Server.php(283): Sabre\\\\DAV\\\\Server->exec()\\n#8 \\\/var\\\
/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(35): OCA\\\\DAV\\\\Server->exec()\\n#9 \\\/var\\\/www\\\/html\\\/nextcloud\\\/remote.php(164): require_once('\\\/var\\\/www\\\/html\\\/n...')\\n#10 {main}\
",\"File\":\"\\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php\",\"Line\":201}","userAgent":"curl\/7.52.1","version":"13.0.1.1"}

[arduino43]

I've tried 12-13 and all the same as above.

[najcardboyz]

me too :D

[BurtGummer]

I remove this options from my config:

  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'redis' =>
  array (
    'host' => 'localhost',
    'port' => 6379,
    'timeout' => 0.0,
  ),

upload a file again and it is the same problem. So redis should not be the cause.

Are there any ideas I could still test?

[jonesints]

Is this a duplicate of #8239 ? there seems to be quite a few affected by this just searching on google. best workarounds imply disabling file locking altogether.

[BurtGummer]

'filelocking.enabled' => false,

is not a solution.

[zetric]

Issue still existing in 13.0.2.

'filelocking.enabled' => false,
is not a solution.

:+1:

[arduino43]

For me, the problem also occurs during large file uploads.

Uploading +40GB virtual disk files always fails, despite a 40-60Mbps throughput. This worked fine in v12.

[BurtGummer]

Sorry ... @MorrisJobke any idea how to solv this problem?

[zetric]

Some additional infos from my side.

For testing, I set 'filelocking.enabled' to false and copied a whole folder to the remote location (I use the german "Magentacloud").
This lead to other errors:

So I wanted to verify that the issue is not situated at the storage provider.
I set up an Ubuntu VM in Azure and mounted my target WebDav directory directly as file system via davfs (mount -t davfs ...).

Then I copied (cp -rv) many files within many folders to the remote location and back (I used the nextcloud source folder :wink: )
-> worked well, I achieved about 5-10 files/second; no errors
I also tried it with some larger files and an 1.8 GB ubuntu ISO image. -> copied with about 7 MByte/s; no errors.

So for me it seems to be an issue in the "Sabre" library itself. And disabeling file locking is (for me) also not working.

If I can help out with testing, just let me know.

EDIT: Same in 13.0.3. A colleague in my company told me that he made the same experience in another use case (not nextcloud). There the cause was situated in the frequency the files were pushed to the remote. The client pushed the files to fast for the server. This may be also the cause here, as larger files that take more time to transmit were no problem here while high amount of small files lead to the above error messages.

[vpecinka]

Same problem, came with 13.0.4, swift primary storage, Redis used for filelocking and memory cache as well.

[BurtGummer]

Yes, the problem still exists (have the same version). I have the impression that a lot of new stuff is being developed in nextcloud, but the known bugs are not being fixed.

[MorrisJobke]

@BurtGummer @vpecinka Does it happen reliably for you or only from time to time?

[MorrisJobke]

cc @icewind1991

[MorrisJobke]

And if so: could you enable the locking debug log in the config.php? See config.sample.php for the description.

[BurtGummer]

Hey @MorrisJobke thank you very much for your response.

Yes, the problem happens reliably every time, the upload connection is slow and the file is big. In https://github.com/nextcloud/server/issues/9001#issuecomment-380775689 i had

'filelocking.debug' => true,

filelocking.debug was enabled all the time, I forgot to disable this option.

[BurtGummer]

@zetric https://github.com/nextcloud/server/issues/9001#issuecomment-395954722

This may be also the cause here, as larger files that take more time to transmit were no problem here while high amount of small files lead to the above error messages.

no, thats wrong. please read my tests, i upload one file with 4,4GB and the error occurs. Until now, I have some smaller files with a bigger total size not uploaded, but i'll try it.

[arduino43]

This does happen reliably for me as well.

Not sure if this is too vague to be useful, but I've found anything below 2mbit/s for files 2.5GB or more will fail 100% of the time.

[asengineeringsupport]

I've tested it from several different locations with different upload speeds, from 2 till 100 MBit/s. Internet connections with better performance are able to upload bigger files. The file size does not matter, more the consequence.

I can upload 18GB big files, when its fast enough (internal network). In my test it seems that all uploads fail, when upload time is longer than one hour. The upload goes till 99 percent and at the 100 percent mark the file locking issue appears.

[MorrisJobke]

I can upload 18GB big files, when its fast enough (internal network). In my test it seems that all uploads fail, when upload time is longer than one hour. The upload goes till 99 percent and at the 100 percent mark the file locking issue appears.

Then it all makes a bit more sense: The locks time out after 1 hour. :/

@icewind1991 We need a way to refresh them during the upload. Anything we can do here?

[MorrisJobke]

With #10116 we try to fix some cases where more locks are freed than we got. It's possible that it fixes the issue in here.

[Schmuuu]

Hi,

I ran into such an issue yesterday. After another user was complaining about failing uploads (and then switched over to dropbox again :( ) I tried uploading files myself. When the upload actually finished and the complete file was uploaded, renaming the file failed, because it was locked.

ll files/public-test/
-rw-r-----  1 http http 8.2G Jul 12 14:18 'Showreel(1).mkv.ocTransferId1432038356.part'
-rw-r-----  1 http http 452K Jul 11 16:38  Nextcloud.mp4
-rw-r-----  1 http http 4.4G Jul 12 11:36  Showreel.mkv

As a result, the file doesn't appear in the Nextcloud web gui.
Can you give me an advice please, how I can rename or delete the file safely? I mean, I obviously can rename and delete via SSH, I know, but I don't want to have an inconsistency between file system and NC database. That's why I'm asking.

Here are the two log entries:

{"reqId":"cZdLk6rld1ccITPuLoqC","level":3,"time":"2018-07-12T14:18:01+02:00","remoteAddr":"IP-ADDRESS","user":"--","app":"no app in context","method":"PUT","url":"\/public.php\/webdav\/Showreel.mkv","message":"Exception: {\"Exception\":\"OCP\\\\Lock\\\\LockedException\",\"Message\":\"\\\"files\\\/519524f8b4ef81acfa28f0bb037fab08\\\" is locked\",\"Code\":0,\"Trace\":\"#0 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Common.php(773): OC\\\\Lock\\\\DBLockingProvider->changeLock('files\\\/519524f8b...', 2)\\n#1 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Common->changeLock('files\\\/public-te...', 2, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#2 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/public-te...', 2, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#3 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/public-te...', 2, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#4 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/public-te...', 2, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#5 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/public-te...', 2, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#6 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Wrapper\\\/Wrapper.php(614): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/public-te...', 2, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#7 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/View.php(1965): OC\\\\Files\\\\Storage\\\\Wrapper\\\\Wrapper->changeLock('files\\\/public-te...', 2, Object(OC\\\\Lock\\\\DBLockingProvider))\\n#8 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Node.php(356): OC\\\\Files\\\\View->changeLock('\\\/Showreel.mkv', 2)\\n#9 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php(196): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Node->changeLock(2)\\n#10 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php(156): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id #15)\\n#11 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1096): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('Showreel.mkv', Resource id #15)\\n#12 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(529): Sabre\\\\DAV\\\\Server->createFile('Showreel.mkv', Resource id #15, NULL)\\n#13 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#14 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#15 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#16 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#17 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v1\\\/publicwebdav.php(107): Sabre\\\\DAV\\\\Server->exec()\\n#18 \\\/var\\\/www\\\/nextcloud\\\/public.php(79): require_once('\\\/var\\\/www\\\/nextcl...')\\n#19 {main}\",\"File\":\"\\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Lock\\\/DBLockingProvider.php\",\"Line\":234}","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko\/20100101 Firefox\/61.0","version":"13.0.4.0"}
{"reqId":"cZdLk6rld1ccITPuLoqC","level":4,"time":"2018-07-12T14:18:01+02:00","remoteAddr":"IP-ADDRESS","user":"--","app":"webdav","method":"PUT","url":"\/public.php\/webdav\/Showreel.mkv","message":"Exception: {\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Message\":\"\\\"public-test\\\/Showreel.mkv\\\" is locked\",\"Code\":0,\"Trace\":\"#0 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php(156): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id #15)\\n#1 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1096): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('Showreel.mkv', Resource id #15)\\n#2 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(529): Sabre\\\\DAV\\\\Server->createFile('Showreel.mkv', Resource id #15, NULL)\\n#3 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#4 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#5 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#6 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#7 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v1\\\/publicwebdav.php(107): Sabre\\\\DAV\\\\Server->exec()\\n#8 \\\/var\\\/www\\\/nextcloud\\\/public.php(79): require_once('\\\/var\\\/www\\\/nextcl...')\\n#9 {main}\",\"File\":\"\\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php\",\"Line\":201}","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko\/20100101 Firefox\/61.0","version":"13.0.4.0"}

I applied the above mentioned fix 6 days ago already. So it doesn't work for me.

I'm running:
NC 13.0.4
Redis 4.0.10
Locking settings from the config:

        "filelocking.enabled": true,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 0,
            "timeout": 0,
            "dbindex": 0,
            "password": "***REMOVED SENSITIVE VALUE***"
        },

Help is highly appreciated. More and more users stop using the NC server, due to locking issues since NC 13.0.4 and fall back to dropbox stating, that dropbox simply works -.-'

[linucksrox]

I have had success using the method I described in the other Github issue that is basically a duplicate of this issue: https://github.com/nextcloud/server/issues/8239#issuecomment-398105379
Just remove the locked files from Redis and you should be able to proceed with renaming the file.

[MorrisJobke]

Can you give me an advice please, how I can rename or delete the file safely? I mean, I obviously can rename and delete via SSH, I know, but I don't want to have an inconsistency between file system and NC database. That's why I'm asking.

Run occ files:scan for that user/path and it should be fine again. Then at worst you need to wait 1 hour until the lock expired.

[BurtGummer]

First test with 13.0.5 didn't work:

root@nas:~$ time curl -u USER:xxxxx-xxxxx-xxxxx-xxxxx-xxxxx -T debian-8.7.1-amd64-DVD-2.iso https://example.org/cloud/remote.php/dav/files/USER/nichtDownload/upload/
<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>OCA\DAV\Connector\Sabre\Exception\FileLocked</s:exception>
  <s:message>"nichtDownload/upload/debian-8.7.1-amd64-DVD-2.iso" is locked</s:message>
</d:error>

real    286m30,730s
user    1m27,972s
sys     0m58,888s
root@nas:~$

And again:

root@sa /var/www/html/nextcloud # ls -alh /var/www/html/nextcloud/data/USER/files/nichtDownload/upload/debian-8.7.1-amd64-DVD-2.iso.ocTransferId1727695603.part
-rw-r----- 1 www-data www-data 4,1G Jul 24 15:00 /var/www/html/nextcloud/data/USER/files/nichtDownload/upload/debian-8.7.1-amd64-DVD-2.iso.ocTransferId1727695603.part
root@sa /var/www/html/nextcloud #

The file was automatically deleted after uploading. Interesting is the time from the error in the nextcloud.log:

{"reqId":"czeTb0L4KvpxOI4wzxf3","level":4,"time":"2018-07-24T13:05:42+00:00","remoteAddr":"89.xxx.xxx.xxx","user":"USER","app":"webdav","method":"PUT","url":"\/cloud\/remote.php\/dav\/files\/USER\/nichtDownload\/upload\/debian-8.7.1-amd64-DVD-2.iso","message":"Exception: {\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Message\":\"\\\"nichtDownload\\\/upload\\\/debian-8.7.1-amd64-DVD-2.iso\\\" is locked\",\"Code\":0,\"Trace\":\"#0 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php(156): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id #12)\\n#1 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1096): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('debian-8.7.1-am...', Resource id #12)\\n#2 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(529): Sabre\\\\DAV\\\\Server->createFile('files\\\/USER\\\/ni...', Resource id #12, NULL)\\n#3 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#4 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#5 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#6 \\\/var\\\/www\\\/html\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#7 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Server.php(287): Sabre\\\\DAV\\\\Server->exec()\\n#8 \\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(35): OCA\\\\DAV\\\\Server->exec()\\n#9 \\\/var\\\/www\\\/html\\\/nextcloud\\\/remote.php(164): require_once('\\\/var\\\/www\\\/html\\\/n...')\\n#10 {main}\",\"File\":\"\\\/var\\\/www\\\/html\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php\",\"Line\":212}","userAgent":"curl\/7.52.1","version":"13.0.5.2"}

because the upload was locked after 15:00, but the error is from 13:05? (date/time from the server is correct)

[samtygier]

I can still trigger this in 13.0.5.2 (snap version). I am testing with several thousand small files.

{"reqId":"0Dj7eVp4enqgfKoPA2AN","level":2,"time":"2018-08-11T20:40:46+00:00","remoteAddr":"192.168.1.1","user":"--","app":"core","method":"GET","url":"\/ind
ex.php\/204","message":"Login failed: 'Bart' (Remote IP: '192.168.1.1')","userAgent":"Mozilla\/5.0 (Android) ownCloud-android\/3.2.1","version":"13.0.5.2"}
{"reqId":"MnZxvfywAhFcKnL8OU1Y","level":4,"time":"2018-08-11T20:46:03+00:00","remoteAddr":"192.168.1.1","user":"x61","app":"webdav","method":"PUT","url":"\/remote.php\/dav\/files\/x61\/files_test\/mt\/eckztljp","message":"Exception: {\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Message\":\"\\\"files_test\\\" is locked\",\"Code\":0,\"Trace\":\"#0 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1096): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('eckztljp', Resource id #21)\\n#1 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(529): Sabre\\\\DAV\\\\Server->createFile('files\\\/x61\\\/files...', Resource id #21, NULL)\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#5 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/apps\\\/dav\\\/lib\\\/Server.php(287): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(35): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/remote.php(164): require_once('\\\/snap\\\/nextcloud...')\\n#9 {main}\",\"File\":\"\\\/snap\\\/nextcloud\\\/8267\\\/htdocs\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":168}","userAgent":"Mozilla\/5.0 (Linux) mirall\/2.3.3 (Nextcloud)","version":"13.0.5.2"}

and at the client end

||mt/eckztljp|INST_NEW|Up|1534019725||11790||3|Error transferring https://xxxx.ddns.net/remote.php/dav/files/x61/files_test/mt/eckztljp - server replied: Locked ("files_test" is locked)|423|0|0|||INST_NONE|

In this case the files did make it onto the server, but I am worried that there is a relation to nextcloud/desktop/issues/506

[sooslaca]

+1 here

With slow upload same happens. When upload is quick no issues.

My log contains:

Error | no app in context | OCP\Lock\LockedException: "files/334bb07d03dc1abaafe783db82c18398" is locked, existing lock on file: none
-- | -- | --

Right after that:

Fatal | webdav | OCA\DAV\Connector\Sabre\Exception\FileLocked: "<<filename_and_url_here>>" is locked
-- | -- | --

[bobblkabb]

Same here (13.0.6 on Ubuntu 18.04). 2.7GB over 1Mbit connection was locked after 6-7 hours. Probably just before the end.

[BurtGummer]

I uploaded a 1,7GB file in the browser to a Nextcloud link that was enabled for editing (I did this in another browser where I was logged in to Nextcloud). So I didn't have to enter a user/password to upload the file. Nevertheless, the upload broke off again when the upload was finished. So it should have nothing to do with whether you are logged in as a user or not.

[BurtGummer]

My first test with 14.0.2 - so far successful!

I have upload 2 files, one with 1,4G and one with 1,7G, time was longer as one hour with 2mb/s cable connection. I try more uploads now.

Interesting: there is no more .part-file in the upload directory from nextcloud?

[Proton23]

Thank you for this Information, I'm very happy to hear that. I will test it within the next days and give feedback on this.

[BurtGummer]

Noo, glad too early:

root@nas:~$ time curl -u USER:xxxxxxxxxxxx -T debian-8.7.1-amd64-DVD-2.iso https://example.org/cloud/remote.php/dav/files/USER/nichtDownload/TestUploadFett/
<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>OCA\DAV\Connector\Sabre\Exception\FileLocked</s:exception>
  <s:message>"nichtDownload/TestUploadFett/debian-8.7.1-amd64-DVD-2.iso" is locked</s:message>
</d:error>

real    289m53,312s
user    1m37,040s
sys     1m3,880s
root@nas:~$

sorry... :-(

[BurtGummer]

I'd like to give a (known) developer from Nextcloud root access to my private root server running Nextcloud in the current version 14, where the problem has existed for years. Maybe this way a developer can find out where the problem is and find a solution? a spark of hope...

[tfvlrue]

I can confirm that this is also happening on my Nextcloud 14 instance. It seems that if the upload over WebDAV takes longer than an hour, the transferred file disappears from the server and it logs two errors like:

Fatal webdav OCA\DAV\Connector\Sabre\Exception\FileLocked: "xxx" is locked
Error no app in context OCP\Lock\LockedException: "files/9f6f03d7935642c2bad854c2d45a890d" is locked

I am using APCu for caching and have not explicitly configured memcache.locking
'memcache.local' => '\OC\Memcache\APCu',

Has anyone found a workaround for this?
Let me know if there is any more information I can provide. This is 100% reproducible for me. Thanks.

[ErAzOr2k]

issue still persists in Nextcloud 15.0.2 :/

[ErAzOr2k]

this issue is not redis related. It's file locking in general.

I setup a new nextcloud installation without redis and file lock enabled. Issue is still the same --> upload longer than 1 hour leads to 0kb file.

With file lock disabled everything is fine.

[BurtGummer]

This bug is a endless story... :-( should have the label "High"...

[icewind1991]

Please see if https://github.com/nextcloud/server/pull/13739 fixes the issue for you

[arduino43]

Still an issue. This should be marked as high - we stopped using NextCloud in production because of this issue.

[MorrisJobke]

Still an issue. This should be marked as high - we stopped using NextCloud in production because of this issue.

Did you tested the PR from @icewind1991? Did you also waited long enough so that the locks are not there from before the patch was applied. The locks have a TTL of 1 hour. So either clear them (with the risk of running into a concurrent request) or wait for at least 1 hour.

[BurtGummer]

I have to wait until the next version 15.0.3 because I don't know how to apply the patch. I can hardly wait.

[BurtGummer]

And I've already had hope.... install 15.0.3 and upload a big file:

root@nas:~$ time curl -u USER:XXXXXXXXXXXXXXXXXXXX -T debian-8.7.1-amd64-DVD-2.iso https://example.org/cloud/remote.php/dav/files/USER/nichtDownload/TestUploadFett/
<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>OCA\DAV\Connector\Sabre\Exception\FileLocked</s:exception>
  <s:message>"nichtDownload/TestUploadFett/debian-8.7.1-amd64-DVD-2.iso" is locked</s:message>
</d:error>

real    110m58,305s
user    1m39,624s
sys     1m1,492s
root@nas:~$

nextcloud.log:

[no app in context] Error: OCP\Lock\LockedException: "files/cdc2372d3f4a0f3d2ded01f9ad0bdabc" is locked at <<closure>>

 0. /var/www/html/nextcloud/lib/private/Files/Storage/Common.php line 778
    changeLock("files/cdc2372d3f4a0f3d2ded01f9ad0bdabc", 2)
 1. /var/www/html/nextcloud/lib/private/Files/Storage/Wrapper/Wrapper.php line 615
    changeLock("files/nichtDown ... o", 2, OC\Lock\DBLockingProvider {})
 2. /var/www/html/nextcloud/lib/private/Files/Storage/Wrapper/Wrapper.php line 615
    changeLock("files/nichtDown ... o", 2, OC\Lock\DBLockingProvider {})
 3. /var/www/html/nextcloud/lib/private/Files/View.php line 1970
    changeLock("files/nichtDown ... o", 2, OC\Lock\DBLockingProvider {})
 4. /var/www/html/nextcloud/apps/dav/lib/Connector/Sabre/Node.php line 359
    changeLock("/nichtDownload/ ... o", 2)
 5. /var/www/html/nextcloud/apps/dav/lib/Connector/Sabre/File.php line 219
    changeLock(2)
 6. /var/www/html/nextcloud/apps/dav/lib/Connector/Sabre/Directory.php line 156
    put(null)
 7. /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php line 1096
    createFile("debian-8.7.1-amd64-DVD-2.iso", null)
 8. /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/CorePlugin.php line 525
    createFile("files/USER/ni ... o", null, null)
 9. <<closure>>
    httpPut(Sabre\HTTP\Reque ... "}, Sabre\HTTP\Response {})
10. /var/www/html/nextcloud/3rdparty/sabre/event/lib/EventEmitterTrait.php line 105
    call_user_func_array([Sabre\DAV\CorePlugin {},"httpPut"], [Sabre\HTTP\Requ ... }])
11. /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php line 479
    emit("method:PUT", [Sabre\HTTP\Requ ... }])
12. /var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php line 254
    invokeMethod(Sabre\HTTP\Reque ... "}, Sabre\HTTP\Response {})
13. /var/www/html/nextcloud/apps/dav/lib/Server.php line 301
    exec()
14. /var/www/html/nextcloud/apps/dav/appinfo/v2/remote.php line 35
    exec()
15. /var/www/html/nextcloud/remote.php line 163
    require_once("/var/www/html/n ... p")

PUT /cloud/remote.php/dav/files/USER/nichtDownload/TestUploadFett/debian-8.7.1-amd64-DVD-2.iso
from 89.xxx.xxx.xxx by USER at 2019-02-07T12:17:25+00:00

:-(

[joukos]

I also struggled quite a while with this, it was a showstopper and a huge PITA because testing any changes would always take at least an hour and it's not very obvious why there should be a locking problem in this situation.

I used to test this with curl and slowing down the transfer to ensure it took long enough:

root@uploadtest:~# time curl -u "SomeUser:SomePassword123" -T 500MB.zero --limit-rate 100k "https://myserver/remote.php/webdav/SomeDir/500MB.zero"

But after the transfer was done (about 85 minutes), I always got:

<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>OCA\DAV\Connector\Sabre\Exception\FileLocked</s:exception>
  <s:message>"SomeDir/500MB.zero" is locked</s:message>
</d:error>

During the transfer I could see the file grow in /var/snap/nextcloud/common/nextcloud/tmp/phpXXXXXX but when all of the data had transferred, I would get the 423 error and the temporary file would disappear from the filesystem, never to be seen again.

I also tried with cadaver (and a 100GB file) but it suffered from the same problem:

dav:/remote.php/webdav/SomeDir/> put 100GB.zero 
Uploading 100GB.zero to `/remote.php/webdav/SomeDir/100GB.zero':
Progress: [=============================>] 100.0% of 107374182400 bytes failed:
423 Locked

I tried the other options mentioned here and in other issues, such as disabling file locking, but when setting filelocking.enabled to false I could still see <filelocking.enabled>yes</filelocking.enabled> in https://myserver/ocs/v2.php/apps/serverinfo/api/v1/info, so I'm not sure if it was ever really disabled. I also tried disabling Redis for the locks and could see oc_file_locks getting populated in the database, but none of this seemed to have any effect to the problem of failing uploads that last too long.

After exhausting the other options, I finally stumbled upon a parameter filelocking.ttl (https://github.com/nextcloud/server/blob/master/config/config.sample.php#L1602).

I was using the latest stable snap (15.0.8snap3) so ran:

# set it to 12 hours
/snap/bin/nextcloud.occ config:system:set filelocking.ttl --value=43200
snap restart nextcloud

And now it works!

dav:/remote.php/webdav/SomeDir/> put 100GB.zero 
Uploading 100GB.zero to `/remote.php/webdav/SomeDir/100GB.zero':
Progress: [=============================>] 100.0% of 107374182400 bytes succeeded.

Also with curl:

root@uploadtest:~# time curl -u "SomeUser:SomePassword123" -T 500MB.zero --limit-rate 100k "https://myserver/remote.php/webdav/SomeDir/500MB.zero"

real    85m20.745s
user    0m2.131s
sys     0m3.961s

I noticed in older threads that people have tweaked max_execution_time for PHP too (https://help.nextcloud.com/t/big-file-is-locked-after-upload-no-upload-redis-used-update-to-12-0-1/19042/9) and saw the following in webdav.php (https://github.com/nextcloud/server/blob/master/apps/dav/appinfo/v1/webdav.php#L30-L33, referenced in the logs when these errors occurred):

// no php execution timeout for webdav
if (strpos(@ini_get('disable_functions'), 'set_time_limit') === false) {
  @set_time_limit(0);
}

However, in config.sample.php it says:

/**
 * Set the lock's time-to-live in seconds.
 *
 * Any lock older than this will be automatically cleaned up.
 *
 * Defaults to ``60*60`` seconds (1 hour) or the php
 *             max_execution_time, whichever is higher.
 */
'filelocking.ttl' => 60*60,

So if I understand this correctly, even if I tweaked max_execution_time for PHP, in the WebDAV context this would be set to 0 so the execution time is not a problem. But if a value for filelocking.ttl is not set (since it's just mentioned in the sample config), there is also a default value of 3600 hardcoded in https://github.com/nextcloud/server/blob/master/lib/private/Server.php#L855 that causes the 1 hour deadline with default settings, unless max_execution_time is set to more than an hour:

$ttl = $config->getSystemValue('filelocking.ttl', max(3600, $ini->getNumeric('max_execution_time')));

The serverinfo page shows the max_execution_time value to be the same:

<max_execution_time>3600</max_execution_time>

So perhaps setting the max_execution_time would help here too, but may be less desirable than setting the locking TTL. I haven't tried it.

The relevant options in my config when this thing started to work were:

"version": "15.0.8.1",
"memcache.local": "\\OC\\Memcache\\Redis",
"memcache.locking": "\\OC\\Memcache\\Redis",
"filelocking.debug": "false",
"filelocking.enabled": "true",
"filelocking.ttl": "43200"

There may be more issues related to this but in my case this ultimately seemed to solve the "uploads over 1 hour fail" problem. Hope this helps.

[BurtGummer]

Hello joukos,

thank you for your work. I have set:

'filelocking.ttl' => 43200,

in my config.php and upload a large File: yes, it works!

But now the question is, is this solution safe?
Shouldn't Nextcloud solve the problem?
What do the developers say? @MorrisJobke @icewind1991

[MorrisJobke]

But now the question is, is this solution safe?
Shouldn't Nextcloud solve the problem?
What do the developers say? @MorrisJobke @icewind1991

Good question. It is save to raise the TTL IMO, but you buy in another downside, that if a process crashes for some reason and does not clean the locks you need to wait longer to access the resources again. :/

[Commifreak]

I have the same or similar issue. Redis is enabled but "xxx is locked" appears after one minute of uploading many small files/folders via webinterface. PHP max_exec is 3600. Is there anything I can check?

NC: 18.0.4

Details here: https://github.com/nextcloud/nextcloud-snap/issues/884#issuecomment-627147101

Thanks in advance!