Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Deletion of several folders or files fails when using external storages. #28779

Closed
SergioBertolinSG opened this issue Aug 23, 2017 · 43 comments · Fixed by #28853
Closed

Deletion of several folders or files fails when using external storages. #28779

SergioBertolinSG opened this issue Aug 23, 2017 · 43 comments · Fixed by #28853
Assignees
Labels
p1-urgent Critical issue, need to consider hotfix with just that issue regression sev1-critical status/STALE Type:Bug
Milestone

Comments

@SergioBertolinSG
Copy link
Contributor

Steps to reproduce

  1. Set up an external storage. For example SFTP.
  2. In oC files view create three or more folders and upload files inside them.
  3. Select three of the created folders and try to delete them.

Expected behaviour

All folders are removed.

Actual behaviour

There are errors. The first one is erased, but the next are locked.

Server configuration

Operating system:
Ubuntu 16.04

Web server:
Apache

Database:
MySQL

PHP version:
7.0

ownCloud version: (see ownCloud admin page)
(current master not stable10)
{"installed":"true","maintenance":"false","needsDbUpgrade":"false","version":"10.0.3.0","versionstring":"10.0.3 beta","edition":"Community","productname":"ownCloud"}

Updated from an older ownCloud or fresh install:
Fresh

The content of config/config.php:


Are you using external storage, if yes which one: local/smb/sftp/...
Yes. SFTP

Are you using encryption:
No.

Logs

{"reqId":"pUh0lrgWVTKkcFPHk2Y7","level":4,"time":"2017-08-23T11:00:34+00:00","remoteAddr":"HIDDEN_IP","user":"admin","app":"webdav","method":"DELETE","url":"\/remote.php\/dav\/files\/admin\/SFTP\/FOLDER3","message":"Exception: {\"Message\":\"HTTP\\\/1.1 423 \\\"SFTP\\\/FOLDER3\\\" is locked\",\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Code\":0,\"Trace\":\"#0 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#1 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(287): Sabre\\\\DAV\\\\Tree->delete('files\\\/admin\\\/SFT...')\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpDelete(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:DELETE', Array)\\n#5 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/opt\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(234): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/opt\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/opt\\\/owncloud\\\/remote.php(175): require_once('\\\/opt\\\/owncloud\\\/a...')\\n#9 {main}\",\"File\":\"\\\/opt\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":330,\"User\":\"admin\"}"}
{"reqId":"1VUz6STOPw52f35meTsC","level":4,"time":"2017-08-23T11:00:34+00:00","remoteAddr":"HIDDEN_IP","user":"admin","app":"webdav","method":"DELETE","url":"\/remote.php\/dav\/files\/admin\/SFTP\/FOLDER2","message":"Exception: {\"Message\":\"HTTP\\\/1.1 423 \\\"SFTP\\\/FOLDER2\\\" is locked\",\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Code\":0,\"Trace\":\"#0 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#1 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(287): Sabre\\\\DAV\\\\Tree->delete('files\\\/admin\\\/SFT...')\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpDelete(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:DELETE', Array)\\n#5 \\\/opt\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/opt\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(234): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/opt\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/opt\\\/owncloud\\\/remote.php(175): require_once('\\\/opt\\\/owncloud\\\/a...')\\n#9 {main}\",\"File\":\"\\\/opt\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":330,\"User\":\"admin\"}"}

Client configuration

Browser
Chrome

Ref: https://github.com/owncloud/files_onedrive/issues/37

@SergioBertolinSG SergioBertolinSG added Type:Bug p1-urgent Critical issue, need to consider hotfix with just that issue sev1-critical labels Aug 23, 2017
@SergioBertolinSG SergioBertolinSG added this to the QA milestone Aug 23, 2017
@PVince81 PVince81 self-assigned this Aug 23, 2017
@PVince81
Copy link
Contributor

Does it happen on stable10 too ?

@SergioBertolinSG
Copy link
Contributor Author

The reference issue was tested in stable10, so it happens there as well.

@PVince81
Copy link
Contributor

And likely doesn't happen on the home storage ? Does it happen with "local" as external storage ?

@SergioBertolinSG
Copy link
Contributor Author

Happens also using local external storage. (Using master)

@PVince81
Copy link
Contributor

but does not happen for a home storage ?

@PVince81
Copy link
Contributor

Reproduced locally with stable10 and SFTP

@SergioBertolinSG
Copy link
Contributor Author

but does not happen for a home storage ?

Only happens using external storage.

@PVince81
Copy link
Contributor

@SergioBertolinSG I've now tried with locking with redis and the problem did not appear.

I wonder if some deadlock or something is happening with DB based locking.

@PVince81
Copy link
Contributor

With DB locking:

{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:06+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:06+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 2 \"scanner::\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:06+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:06+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"\""}
{"reqId":"tFQFFO6jW9Q9V04QqMH2","level":0,"time":"2017-08-24T15:58:06+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"acquireLock: 1 \"\""}
{"reqId":"tFQFFO6jW9Q9V04QqMH2","level":0,"time":"2017-08-24T15:58:06+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"acquireLock: 2 \"scanner::\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"sub\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"sub\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"b\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"b\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"c\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"c\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"a\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"a\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 2 \"scanner::\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"b\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 2 \"scanner::\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"\""}
{"reqId":"tFQFFO6jW9Q9V04QqMH2","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"acquireLock: 1 \"c\""}
{"reqId":"tFQFFO6jW9Q9V04QqMH2","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"acquireLock: 1 \"\""}
{"reqId":"K5loY0StCNZ0sCAlwQH0","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"changeLock: 2 \"b\""}
{"reqId":"tFQFFO6jW9Q9V04QqMH2","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"changeLock: 2 \"c\""}
{"reqId":"tFQFFO6jW9Q9V04QqMH2","level":4,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"webdav","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"Exception: {\"Message\":\"HTTP\\\/1.1 423 \\\"sftp\\\/c\\\" is locked\",\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Code\":0,\"Trace\":\"#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(287): Sabre\\\\DAV\\\\Tree->delete('files\\\/admin\\\/sft...')\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpDelete(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:DELETE', Array)\\n#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(234): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/remote.php(175): require_once('\\\/srv\\\/www\\\/htdocs...')\\n#9 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":330,\"User\":\"admin\"}"}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"sub\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"sub\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"b\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 2 \"scanner::a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"a\/data1.dat\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"a\/data1.dat\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 2 \"scanner::a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":0,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"changeLock: 2 \"a\""}
{"reqId":"5znIiOYwLf2rj1YaRn18","level":4,"time":"2017-08-24T15:58:07+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"webdav","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"Exception: {\"Message\":\"HTTP\\\/1.1 423 \\\"sftp\\\/a\\\" is locked\",\"Exception\":\"OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Exception\\\\FileLocked\",\"Code\":0,\"Trace\":\"#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(287): Sabre\\\\DAV\\\\Tree->delete('files\\\/admin\\\/sft...')\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpDelete(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:DELETE', Array)\\n#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(234): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/remote.php(175): require_once('\\\/srv\\\/www\\\/htdocs...')\\n#9 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":330,\"User\":\"admin\"}"}

@PVince81
Copy link
Contributor

There are scanner entries for the locks. I tried setting the ext storage mode to "Never" check for changes, still the locking errors appear. Well, now it's worse: I get 403 for all three calls:

{"reqId":"aEe3ailMDwK3g8voUwJ3","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"acquireLock: 1 \"c\""}
{"reqId":"aEe3ailMDwK3g8voUwJ3","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"acquireLock: 1 \"\""}
{"reqId":"aEe3ailMDwK3g8voUwJ3","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"changeLock: 2 \"c\""}
{"reqId":"YLFZfreYEFI9VAxYOXu4","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"a\""}
{"reqId":"YLFZfreYEFI9VAxYOXu4","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"acquireLock: 1 \"\""}
{"reqId":"YLFZfreYEFI9VAxYOXu4","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"changeLock: 2 \"a\""}
{"reqId":"6FMaUHxwrabqWDO8tTdF","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"b\""}
{"reqId":"6FMaUHxwrabqWDO8tTdF","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"acquireLock: 1 \"\""}
{"reqId":"6FMaUHxwrabqWDO8tTdF","level":0,"time":"2017-08-24T16:02:56+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"changeLock: 2 \"b\""}
{"reqId":"aEe3ailMDwK3g8voUwJ3","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"changeLock: 1 \"c\""}
{"reqId":"aEe3ailMDwK3g8voUwJ3","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"releaseLock: 1 \"c\""}
{"reqId":"aEe3ailMDwK3g8voUwJ3","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"releaseLock: 1 \"\""}
{"reqId":"6FMaUHxwrabqWDO8tTdF","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"changeLock: 1 \"b\""}
{"reqId":"YLFZfreYEFI9VAxYOXu4","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"changeLock: 1 \"a\""}
{"reqId":"YLFZfreYEFI9VAxYOXu4","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"a\""}
{"reqId":"6FMaUHxwrabqWDO8tTdF","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"b\""}
{"reqId":"YLFZfreYEFI9VAxYOXu4","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"releaseLock: 1 \"\""}
{"reqId":"6FMaUHxwrabqWDO8tTdF","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"releaseLock: 1 \"\""}
{"reqId":"aEe3ailMDwK3g8voUwJ3","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"webdav","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/c","message":"Exception: {\"Message\":\"HTTP\\\/1.1 403 Forbidden\",\"Exception\":\"Sabre\\\\DAV\\\\Exception\\\\Forbidden\",\"Code\":0,\"Trace\":\"#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(287): Sabre\\\\DAV\\\\Tree->delete('files\\\/admin\\\/sft...')\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpDelete(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:DELETE', Array)\\n#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(234): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/remote.php(175): require_once('\\\/srv\\\/www\\\/htdocs...')\\n#9 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":325,\"User\":\"admin\"}"}
{"reqId":"YLFZfreYEFI9VAxYOXu4","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"webdav","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/a","message":"Exception: {\"Message\":\"HTTP\\\/1.1 403 Forbidden\",\"Exception\":\"Sabre\\\\DAV\\\\Exception\\\\Forbidden\",\"Code\":0,\"Trace\":\"#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(287): Sabre\\\\DAV\\\\Tree->delete('files\\\/admin\\\/sft...')\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpDelete(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:DELETE', Array)\\n#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(234): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/remote.php(175): require_once('\\\/srv\\\/www\\\/htdocs...')\\n#9 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":325,\"User\":\"admin\"}"}
{"reqId":"6FMaUHxwrabqWDO8tTdF","level":0,"time":"2017-08-24T16:03:17+00:00","remoteAddr":"127.0.0.1","user":"admin","app":"webdav","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/admin\/sftp\/b","message":"Exception: {\"Message\":\"HTTP\\\/1.1 403 Forbidden\",\"Exception\":\"Sabre\\\\DAV\\\\Exception\\\\Forbidden\",\"Code\":0,\"Trace\":\"#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(287): Sabre\\\\DAV\\\\Tree->delete('files\\\/admin\\\/sft...')\\n#2 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpDelete(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:DELETE', Array)\\n#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#6 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(234): Sabre\\\\DAV\\\\Server->exec()\\n#7 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#8 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/remote.php(175): require_once('\\\/srv\\\/www\\\/htdocs...')\\n#9 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php\",\"Line\":325,\"User\":\"admin\"}"}

@PVince81
Copy link
Contributor

For the case with "check updates" enabled which matches this original report, what I observe when deleting three folders "a", "b" and "c" on external storage:

The DELETE call for "b" apparently also shortly sets a shared lock on "a", "b" and also "c" instead of just "b". Not sure why, could be the scanner checking their hasUpdated values.
If at exactly this time, the concurrent DELETE for "a" comes, it tries to get an exclusive lock on "a". If "a" has a shared lock due to the above, it will fail with "LockedException" which is expected.

Now the first thing that comes to mind is the RetryLockingWrapper attempt I made: #28544 (unfinished, buggy). If this one could work then instead of failing directly it would at least retry later.

Next steps:

  • confirm that the shared locks above are from the scanner
  • if yes, find out why disabling the scanner (set "check for updates" to "never") still has issues
  • think of alternatives to fix this aside from RetryLockingWrapper

cc @jvillafanez

@jvillafanez
Copy link
Member

@PVince81
Copy link
Contributor

Thanks, this looks scary: a caldav plugin triggering opendir / scanning ?!

In general I wondered whether we should simply disable any scanning when the operation is not PROPFIND, GET or MOVE. It doesn't make much sense to rescan for changes for a DELETE.

Hmmm, well... maybe it does, because a DELETE moves stuff to trashbin and needs the filecache entries to be up to date before moving ?

@jvillafanez
Copy link
Member

I think the most important thing is to know what is causing the lock of the parent folder, which, I guess, is what is preventing the rest of the deletions to be executed. Ideally, you should only lock the folder you're going to delete, so you shouldn't collide with the deletion of other sibling folders.

Whether we should (deep) scan the deleted folder or not, that's a decision for the trashbin app, not for core, but it should only affect to the folder that's going to be deleted. This implies that deletion of sibling folders shouldn't collide with eachother

@SergioBertolinSG
Copy link
Contributor Author

SergioBertolinSG commented Aug 25, 2017

Tested using redis (https://github.com/owncloud/files_onedrive/issues/37#issuecomment-324879207)

Works fine, no errors.

But another bug has appeared:

#28800

@jvillafanez
Copy link
Member

Did you tested with several big folders? In this case the deletion should take some time since it needs to move the contents to the trashbin.

If it works in this scenario with redis, it will likely be a problem in the DB implementation.

@PVince81
Copy link
Contributor

I just tried with the RetryLockingProvider out of curiosity, but it doesn't solve the problem: #28544. Anyway, this PR isn't ready as it doesn't seem to retry properly.

@PVince81
Copy link
Contributor

Oh, if I set "filelocking.retrydelay" to 5000 in #28544 then the deletion work. But I suspect that the retry delay might need to be high enough to cover for the rescan cost... Might be a quick general workaround but the real solution would be to prevent the rescan in the first place.

@SergioBertolinSG
Copy link
Contributor Author

SergioBertolinSG commented Aug 30, 2017

Not happening using 10.0.2.

@PVince81
Copy link
Contributor

Ah! Then there is hope!

@PVince81
Copy link
Contributor

I'll bisect this

@PVince81
Copy link
Contributor

I added some logging in the locking code to log what path is logged when, including stack traces, and this for both endpoints. There are bigger differences: https://cloud.owncloud.com/index.php/s/VK1ncpEUdvhScz9

Now need to take some time to analyze this...

@PVince81
Copy link
Contributor

additional note: the above was produced with minimal Sabre plugins on new dav

@PVince81
Copy link
Contributor

The first acquireLock in old DAV is done directly on "a", the folder to delete.
In new DAV, it acquires a lock on the parent.

It seems it's due to the differences in getNodeForPath from ObjectTree which we had in old dav.
We don't have it any more in new dav, so it falls back to Tree::getNodeForPath which itself first does a getNodeForPath on the parent node, which itself would cause a getFileInfo() on the parent, which explains why a lock is set higher. And calling getFileInfo() would likely trigger additional hasUpdated calls (to be confirmed).

I don't think we can use our custom ObjectTree like we did before, because now the node tree isn't only about files but also about collections of different types.

So we either need to make sure that such getFileInfo calls on the parents don't trigger additional locks or scans, or find a way to provide a shortcut for quicker node access in the file tree collections.

@PVince81
Copy link
Contributor

Making FileInfo lazy for the tree traversal algo is not an option because we need to getFileInfo to find out if a node even exists.

So far the only way I see is to bring back a custom ObjectTree implementation which itself will detect if we're querying a under "files/$userId". If yes, then shortcut a bit and go directly to the target node.

@PVince81
Copy link
Contributor

PVince81 commented Aug 30, 2017

  • bring back ObjectTree for direct node access
  • calendar plugins messing up ? => no, they don't
  • DAVACL plugin messing up

@PVince81
Copy link
Contributor

Pfff, the reason why DAVACL is messing up too is because it's checking privileges on all parents recursively. So when we do an operation on "files/$userId/sftp/a" it will recurse through every parent and call getNodeForPah() on each, which triggers the same issue like the default object tree.

We could prevent DAVACL to check every parent when dealing with the "files/*" subtree as a workaround...

Seems these are many workarounds due to the fact that accessing every parent is expensive and messes up with locks.

@PVince81
Copy link
Contributor

Another completely different solution that comes to mind would be to only allow rescanning of everything that is below the currently requested node. If one of the parent nodes is retrieved, don't rescan or check for changes. This would likely solve the locking issue but not the filecache performance issue as we'd still be querying the file cache for every parent due to Sabre node iteration.

@PVince81
Copy link
Contributor

The subtle thing about parallel operations on an external storage with update detection enabled is that one of the operation operates on disk and the second operation might detect this change on-disk first before the first operation finishes. This is why we need to keep scanner locking anyway.

@PVince81
Copy link
Contributor

First working fix, the one with the tree shortcut and disabling DAVACL: #28853

@jvillafanez @SergioBertolinSG this solves the problem but might not be a satisfactory solution.

I'll have a look if an alternative solution like #28779 (comment) is possible...

@PVince81
Copy link
Contributor

Worst case we revert web UI to use the old DAV endpoint. However this doesn't exclude issues with parallel deletion initiated by newer desktop clients which use the new DAV endpoint...

@PVince81
Copy link
Contributor

POC of alternative solution: limits the watcher to any subpaths of the currently requested path: #28855. So whenever any of the parents gets queried by the Sabre tree, the watcher/scanner doesn't kick in.

The part I dislike about this approach is that it doesn't solve the parent querying / filecache queries like #28853 does.

@PVince81
Copy link
Contributor

PVince81 commented Sep 5, 2017

Despite the fact that the desktop client 2.3.3 is using the new DAV endpoint and is doing the three DELETE operations in parallel, I didn't manage to run into the locking situation.

Maybe the browser doesn't do it exactly in parallel but with a slight microscopic delay ?

Anyway, this makes this bug less critical. I think we'll switch the web UI to old DAV in the meantime.

Because the fix itself #28853 is complex and requires more discussions regarding the DAV architecture.

@PVince81
Copy link
Contributor

PVince81 commented Sep 5, 2017

This PR reverts the web UI back to the old DAV endpoint as a workaround for the next release: #28914

@SergioBertolinSG
Copy link
Contributor Author

This works in current master, close?

@PVince81
Copy link
Contributor

PVince81 commented Sep 7, 2017

Ok, let's close. We'll need to redo the switch to new DAV, I'll put this on my PR #28853

@PVince81 PVince81 closed this as completed Sep 7, 2017
@PVince81
Copy link
Contributor

PVince81 commented Sep 7, 2017

actually I've put the switch in a separate PR here: #28874 which also contains switching for single file uploads

@lock
Copy link

lock bot commented Aug 1, 2019

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@lock lock bot locked as resolved and limited conversation to collaborators Aug 1, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
p1-urgent Critical issue, need to consider hotfix with just that issue regression sev1-critical status/STALE Type:Bug
Projects
None yet
5 participants