Concurrent PROPFINDs result in error 500

[davivel]

Steps to reproduce

1. Create a folder /c/a/ in your account (not sure if meaningful).
2. Run

for (( c=1; c<=5; c++ )) 
do 
curl --user <user>:<pass> -X PROPFIND -o out${c}.txt -H "Content-Type: text/xml" -d "<?xml version='1.0' encoding='utf-8' ?><D:propfind xmlns:D='DAV:'><D:allprop/></D:propfind>" http://<domain/path>remote.php/webdav/c/a/ &
done

Expected behaviour

All requests should finish with HTTP code 207; files out1.txt to out5.txt should contain the properties of the folder /c/a/, something like:

<?xml version="1.0" encoding="utf-8"?>
<d:multistatus xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns" xmlns:oc="http://owncloud.org/ns">
  <d:response>
    <d:href>[edited]/remote.php/webdav/c/a/</d:href>
      <d:propstat>
        <d:prop>
          <oc:id>00000044ocee3337d5cf</oc:id>
          <oc:permissions>RDNVCK</oc:permissions>
          <d:getetag>"54c75bef2d6bc"</d:getetag>
          <d:getlastmodified>Tue, 27 Jan 2015 09:35:43 GMT</d:getlastmodified>
          <d:resourcetype><d:collection/></d:resourcetype>
          <d:quota-used-bytes>0</d:quota-used-bytes>
          <d:quota-available-bytes>6199443456</d:quota-available-bytes>
        </d:prop>
      <d:status>HTTP/1.1 200 OK</d:status>
    </d:propstat>
  </d:response>
</d:multistatus>

Actual behaviour

4 of 5 methods finish in 500 Internal Error.

Server configuration

ownCloud version: - 8.0.0.4

daily/master

Logs

ownCloud log (data/owncloud.log)

One message

An exception occurred while executing 'UPDATE "oc_preferences" SET "configvalue" = ? WHERE "userid" = ? AND "appid" = ? AND "configkey" = ? ' with params [1422353148, "<user>", "login", "lastLogin"]: SQLSTATE[HY000]: General error: 5 database is locked

is shown per failed request.

Extra

Not only affecting PROPFIND requests, Android client is receiving 500 Internal error when downloads (GET) and refresh (PROPFIND) are run in parallel .

[davivel]

Extra 2: this is no problem for stable7.

[LukasReschke]

Solution: Don't use SQLite.

@DeepDiver1975 Related to our recent discussions with @ogoffart and Co.

[davivel]

Solution: Don't use SQLite.

Sounds fast and clean :)

[karlitschek]

Guys. This is a bug. There is absolutely no technical reason why ownCloud should return a 500 here. The database should be properly locked and the second request should be answered as soon as the first one is done. This is how ownCloud worked for years.
@LukasReschke @DeepDiver1975
Thanks you

[DeepDiver1975]

Guys. This is a bug. There is absolutely no technical reason why ownCloud should return a 500 here.

indeed - the question is how to solve this and at the end what will be the user experience.

The by-design--behavior of sqlite being not concurrent accessible will result in all operations of all users and all clients to be executed sequentially which will be observed as "ownCloud is damn slow"

Let me see if there is a solution to the database locked issue (FYI: drupal is struggling with this issue for 4 years now with no solution at hand - need to take a closer look - https://www.drupal.org/node/1120020).

My suggestion regarding the user experience would be to disable the webdav interface and/or sync in case sqlite is used. To protect us and the user base.

[guruz]

The by-design--behavior of sqlite

...if the busy-wait comes back in as per #13615 (that used to be in oc5 but then got kicked out)

More context for @karlitschek in owncloud/client#2743

Additionally toning down parallelism also helps with timeouts where e.g. a long running move takes several minutes.

[MTRichards]

@carlaschroder Add a release note please about downloading folders in SQLite with Android as a known issue.

And discouraging the use of SQLite in production.

[karlitschek]

We should fix the issue before we discourage the usage of a database.
There is a potential fix here: #13752
Please test

[PVince81]

This issue is still happening. The mentionned fix is only for files.

The problem above is when updating the config concurrently.
It seems that all 5 requests are authenticating and updating the oc_preferences table at the same time to update the "lastlogin" value and locking each other out.
It seems that the first request goes through but the others fail directly.

I suspect there might not be any lock timeout in place which might explain why it directly fails.
I'll try with #13615

[PVince81]

(the config option for the timeout)

[PVince81]

Another possible fix is to fail gracefully (ignore the error) if the "lastlogin" value cannot be updated due to locking.

[PVince81]

Okay, I tried ignoring the "lastlogin" exception and the propfinds all go through. So at least we have a quickfix for this specific situation.

Next step: try the timeout option.

[PVince81]

No luck with #13615, needs further research

[davivel]

So, if all the requests were reusing the same session cookie, all the the PROPFINDs would work?

@rperezb , seems a reason to finally enable the cookie support.

[PVince81]

Yes, that's another "workaround".

[rperezb]

@davivel great for next version expected this sprint

[PVince81]

Here it is: https://github.com/owncloud/core/blob/master/lib/private/allconfig.php#L180

Unclosed cursor, PR is on the way

[PVince81]

Fix is here: #13772

[MorrisJobke]

Thanks @davivel for this nice to test script 👍

[davivel]

Thanks, guys. Android app working again as expected.

[guruz]

@davivel Wondering..does the Android client do multiple PROPFINDs (or other requestz) that all re-authenticate? It does not use cookies to keep the auth?

[davivel]

At this moment, it does.

But right now we only need to change a flag to fix that. Next version (coming soon) should use cookies.