server Performance of WebDAV search requests with many shared files

I have noticed that when many files are shared between users (e.g. via Talk) the WebDAV search requests are quite slow. This is visible in the Photos app when entering the initial page or in the Android client when entering the Media tab. I suspect that this issue #35776 might have the same cause.

After some analysis I have found that in such situation the database query that retrieves the list of files is very complex and takes significant time to execute. For each shared file the following section is added to the SQL WHERE clause:

((`storage` = :dcValueNN) AND (`path_hash` = :dcValueMM)) OR

In my environment I see queries with over 250 sections like this. That makes the query use over 500 separate parameters.

Since usually many files are shared between two users, the storage part of the filter is repeated many times. This provides an opportunity to refactor the query to use the following form (and provide all path_hash values for the same storage in an array):

((`storage` = :dcValueNN) AND (`path_hash` IN (:dcValueMM))) OR

This reduces the number of parameters significantly (in my case to about 25) and seems easier to optimize by the database engine.

In this PR I propose a change to the QuerySearchHelper::searchInCaches method that generates the query refactored as described above.

In my environment (MySQL database, ~250k rows in the oc_filecache table) I measured a very nice improvement in the query execution time (retrieval of the first 200 images in the Photos app):

before the change: ~3700 ms
after the change: ~750 ms

Comments? Thoughts?

Mar 06 '23 22:03 starypatyk

Thoughts:

Maybe the support for IN in the SearchBuilder should work on path and automagically convert to path_hash like it’s done for =.
If possible this should be split into one PR that adds the support for IN and one that uses it to ease revert in case we get into trouble.

Mar 13 '23 10:03 come-nc

@come-nc

Maybe the support for IN in the SearchBuilder should work on path and automagically convert to path_hash like it’s done for =.

Seems doable - but feels more complex and likely more difficult to analyse. On the other hand, I am now wondering if the PathPrefixOptimizer is used at all after my changes. I am not sure how to verify this. I see that the QueryOptimizer is a relatively new piece of code (Aug 2021) created by @icewind1991.

If possible this should be split into one PR that adds the support for IN and one that uses it to ease revert in case we get into trouble.

Certainly possible. Should I go ahead and split this into a separate PR?

Mar 14 '23 21:03 starypatyk

@starypatyk if you need someone to do some testing, just let me know. I've a lot of shares and search is really slow (takes longer than a minute).

Jun 07 '23 15:06 XueSheng-GIT

@XueSheng-GIT

@starypatyk if you need someone to do some testing, just let me know. I've a lot of shares and search is really slow (takes longer than a minute).

Would be great to know if these changes improve performance in other cases. :+1:

Would you be able to pick up my changes directly from GitHub? I have rebased this PR today - it should be easier to apply it on a recent Nextcloud version.

Jun 08 '23 21:06 starypatyk

I've applied this pull to my testing instance (NC 27.0.0). I've added 1,000 shares via talk to a test account (share_NNNN.txt). Because this is especially about webdav search, i took the official reference to perform a search: https://docs.nextcloud.com/server/27/developer_manual/client_apis/WebDAV/search.html

Search for filename 'test' (I hope that's the right way to do this, I never used webdav search so far ;) ):

$ time curl -u username:pass 'https://cloud.domain.invalid/remote.php/dav/' -X SEARCH -H "content-Type: text/xml" --data '<?xml version="1.0" encoding="UTF-8"?>
 <d:searchrequest xmlns:d="DAV:" xmlns:oc="http://owncloud.org/ns">
     <d:basicsearch>
         <d:select>
             <d:prop>
                 <oc:fileid/>
                 <d:displayname/>
                 <d:getcontenttype/>
                 <d:getetag/>
                 <oc:size/>
             </d:prop>
         </d:select>
         <d:from>
             <d:scope>
                 <d:href>/files/username</d:href>
                 <d:depth>infinity</d:depth>
             </d:scope>
         </d:from>
         <d:where>
             <d:like>
                 <d:prop>
                     <d:displayname/>
                 </d:prop>
                 <d:literal>test</d:literal>
             </d:like>
         </d:where>
         <d:orderby/>
    </d:basicsearch>
</d:searchrequest>'
<?xml version="1.0"?>
<d:multistatus xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns" xmlns:oc="http://owncloud.org/ns" xmlns:nc="http://nextcloud.org/ns"/>

real	0m31,679s
user	0m0,043s
sys	0m0,008s

Although, I've applied the patch, the query log still includes all those blocks: (("storage" = $39) AND ("path" = $40)) OR

Full log: webdav-search_patched.log

@starypatyk, anything special which must be done after applying this pull?

Jun 20 '23 18:06 XueSheng-GIT

Hi @XueSheng-GIT,

The patch should "just work" - no special configuration required.

For the next two weeks I will not be able to diagnose this. I should have time in early July.

Jun 20 '23 20:06 starypatyk

Hi @XueSheng-GIT,

Your WebDAV search query looks correct. I have tried it on my dev instance and it behaves as expected - i.e. the sequence of individual conditions like:

((`storage` = :dcValue5) AND (`path` = :dcValue6)) OR

gets replaced by a much shorter list of:

((`storage` = :dcValue5) AND (`path_hash` IN (:dcValue6))) OR

I do not understand yet what may be the reason this does not work for you. I have committed additional diagnostic code that might help me diagnose the issue.

Would you be able to pick the newest version of code from this PR and re-run your tests?

Please make sure to set logging level to DEBUG as described in the documentation and provide relevant fragment of the nextcloud.log file. There should be many lines similar to this:

{"reqId":"vJekSFwbXgIqyHuokfVX","level":0,"time":"2023-07-06T22:07:54+00:00","remoteAddr":"192.168.21.4","user":"admin","app":"no app in context","method":"SEARCH","url":"/remote.php/dav/?log_secret=f9e9137b0bfde6498e70b75c91f6a5c8","message":"generateStorageFilters: cache: OCA\\Files_Sharing\\Cache","userAgent":"curl/7.81.0","version":"28.0.0.0","data":[]}

Jul 06 '23 22:07 starypatyk

@starypatyk thanks for following up.

I've picked up the newest version. Loglevel was already set to DEBUG on my test instance. nextcloud.log contains many of those lines. But Search query is still unchanged and slow.

{"reqId":"fbrG5wnYyA9kLkOlSfVt","level":0,"time":"2023-07-07T14:29:16+02:00","remoteAddr":"fd64:c2a2:5c5e:e201:703c:a494:309:f1e7","user":"usename","app":"no app in context","method":"SEARCH","url":"/remote.php/dav/","message":"generateStorageFilters: cache: OCA\\FilesAccessControl\\CacheWrapper","userAgent":"curl/7.81.0","version":"27.0.0.8","data":[]}

Do you need a more complete log? I don't want to paste it here for privacy reasons.

Jul 07 '23 12:07 XueSheng-GIT

Hi @XueSheng-GIT,

Thank you for the log line. It does help much :+1: A key difference is here:

My environment:

"generateStorageFilters: cache: OCA\\Files_Sharing\\Cache"

Your environment:

"generateStorageFilters: cache: OCA\\FilesAccessControl\\CacheWrapper"

I suspect that you use the File access control app and my code is not prepared to handle this case.

I need to rethink the approach.

Jul 07 '23 21:07 starypatyk

I've disabled File access control to double check the results.

nextcloud log now contains:

{"reqId":"KeYhbHbr8HH0mwj2J6kC","level":0,"time":"2023-07-09T07:28:42+02:00","remoteAddr":"fd64:c2a2:5c5e:e201:b442:4193:b930:e5c8","user":"username","app":"no app in context","method":"SEARCH","url":"/remote.php/dav/","message":"generateStorageFilters: cache: OCA\\Files_Sharing\\Cache","userAgent":"curl/7.81.0","version":"27.0.0.8","data":[]}

Webdav search used:

$ time curl -u username:pass 'https://cloud.domain.invalid/remote.php/dav/' -X SEARCH -H "content-Type: text/xml" --data '<?xml version="1.0" encoding="UTF-8"?>
 <d:searchrequest xmlns:d="DAV:" xmlns:oc="http://owncloud.org/ns">
     <d:basicsearch>
         <d:select>
             <d:prop>
                 <oc:fileid/>
                 <d:displayname/>
                 <d:getcontenttype/>
                 <d:getetag/>
                 <oc:size/>
             </d:prop>
         </d:select>
         <d:from>
             <d:scope>
                 <d:href>/files/username</d:href>
                 <d:depth>infinity</d:depth>
             </d:scope>
         </d:from>
         <d:where>
             <d:like>
                 <d:prop>
                     <d:displayname/>
                 </d:prop>
                 <d:literal>search-string</d:literal>
             </d:like>
         </d:where>
         <d:orderby/>
    </d:basicsearch>
</d:searchrequest>'
<?xml version="1.0"?>
<d:multistatus xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns" xmlns:oc="http://owncloud.org/ns" xmlns:nc="http://nextcloud.org/ns"/>

real	0m1,117s
user	0m0,052s
sys	0m0,004s

pgsql query log: webdav-search_patched+disabledfac.log

That's a major increase in search speed. 31s reduced to 1s!!! Thanks a lot for working on this @starypatyk!

Jul 09 '23 05:07 XueSheng-GIT

Hi @XueSheng-GIT,

That's a major increase in search speed. 31s reduced to 1s!!!

Great to know that this change can help for your case! Thanks :+1:

I am now considering a different approach that should also work with the File access control plugin.

BTW - The queries in your logs seem to suggest that you use PostgreSQL as the database backend. Could you please confirm/deny?

Jul 09 '23 12:07 starypatyk

BTW - The queries in your logs seem to suggest that you use PostgreSQL as the database backend. Could you please confirm/deny?

Yes, I'm using postgreSQL.

Jul 09 '23 12:07 XueSheng-GIT

Hi @XueSheng-GIT,

I have implemented a slightly different approach. The code should now work also when the File access control plugin is active.

Would you be able to get the latest changes and verify?

Jul 11 '23 19:07 starypatyk

After applying the latest changes, webdav search fails (with and without File access control enabled). Reverting to the previous patch makes it work again.

Here's my search and the error message.

curl -u username:pass 'https://cloud.domain.invalid/remote.php/dav/' -X SEARCH -H "content-Type: text/xml" --data '<?xml version="1.0" encoding="UTF-8"?>
 <d:searchrequest xmlns:d="DAV:" xmlns:oc="http://owncloud.org/ns">
     <d:basicsearch>
         <d:select>
             <d:prop>
                 <oc:fileid/>
                 <d:displayname/>
                 <d:getcontenttype/>
                 <d:getetag/>
                 <oc:size/>
             </d:prop>
         </d:select>
         <d:from>
             <d:scope>
                 <d:href>/files/username</d:href>
                 <d:depth>infinity</d:depth>
             </d:scope>
         </d:from>
         <d:where>
             <d:like>
                 <d:prop>
                     <d:displayname/>
                 </d:prop>
                 <d:literal>search-string</d:literal>
             </d:like>
         </d:where>
         <d:orderby/>
    </d:basicsearch>
</d:searchrequest>'

Error message (response within the console):

<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>TypeError</s:exception>
  <s:message>OC\Files\Cache\QuerySearchHelper::checkStorageAndPathFilter(): Argument #1 ($operator) must be of type OCP\Files\Search\ISearchBinaryOperator, OC\Files\Search\SearchComparison given, called in /var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php on line 109</s:message>
</d:error>

nextcloud.log

{"reqId":"GPoTv8fK8thbreYbQvtz","level":3,"time":"2023-07-12T20:15:42+02:00","remoteAddr":"fd64:c2a2:5c5e:e201:1a88:be31:f4b:6ec","user":"username","app":"webdav","method":"SEARCH","url":"/remote.php/dav/","message":"OC\\Files\\Cache\\QuerySearchHelper::checkStorageAndPathFilter(): Argument #1 ($operator) must be of type OCP\\Files\\Search\\ISearchBinaryOperator, OC\\Files\\Search\\SearchComparison given, called in /var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php on line 109","userAgent":"curl/7.81.0","version":"27.0.0.8","exception":{"Exception":"TypeError","Message":"OC\\Files\\Cache\\QuerySearchHelper::checkStorageAndPathFilter(): Argument #1 ($operator) must be of type OCP\\Files\\Search\\ISearchBinaryOperator, OC\\Files\\Search\\SearchComparison given, called in /var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php on line 109","Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php","line":109,"function":"checkStorageAndPathFilter","class":"OC\\Files\\Cache\\QuerySearchHelper","type":"->"},{"file":"/var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php","line":129,"function":"generateStorageFilters","class":"OC\\Files\\Cache\\QuerySearchHelper","type":"->"},{"file":"/var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php","line":218,"function":"applySearchConstraints","class":"OC\\Files\\Cache\\QuerySearchHelper","type":"->"},{"file":"/var/www/nextcloud/lib/private/Files/Node/Folder.php","line":239,"function":"searchInCaches","class":"OC\\Files\\Cache\\QuerySearchHelper","type":"->"},{"file":"/var/www/nextcloud/apps/dav/lib/Files/FileSearchBackend.php","line":191,"function":"search","class":"OC\\Files\\Node\\Folder","type":"->"},{"file":"/var/www/nextcloud/apps/dav/lib/Files/LazySearchBackend.php","line":63,"function":"search","class":"OCA\\DAV\\Files\\FileSearchBackend","type":"->"},{"file":"/var/www/nextcloud/3rdparty/icewind/searchdav/src/DAV/SearchHandler.php","line":82,"function":"search","class":"OCA\\DAV\\Files\\LazySearchBackend","type":"->"},{"file":"/var/www/nextcloud/3rdparty/icewind/searchdav/src/DAV/SearchPlugin.php","line":119,"function":"handleSearchRequest","class":"SearchDAV\\DAV\\SearchHandler","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"searchHandler","class":"SearchDAV\\DAV\\SearchPlugin","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":472,"function":"emit","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/apps/dav/lib/Server.php","line":364,"function":"exec","class":"Sabre\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->"},{"file":"/var/www/nextcloud/remote.php","line":172,"args":["/var/www/nextcloud/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php","Line":83,"message":"OC\\Files\\Cache\\QuerySearchHelper::checkStorageAndPathFilter(): Argument #1 ($operator) must be of type OCP\\Files\\Search\\ISearchBinaryOperator, OC\\Files\\Search\\SearchComparison given, called in /var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php on line 109","exception":[],"CustomMessage":"OC\\Files\\Cache\\QuerySearchHelper::checkStorageAndPathFilter(): Argument #1 ($operator) must be of type OCP\\Files\\Search\\ISearchBinaryOperator, OC\\Files\\Search\\SearchComparison given, called in /var/www/nextcloud/lib/private/Files/Cache/QuerySearchHelper.php on line 109"},"id":"64aeedd504caf"}

This test was done on NC 27.0.0. @starypatyk, any idea why it does fail now?

Jul 12 '23 18:07 XueSheng-GIT

Hi @XueSheng-GIT,

Sorry, this was my mistake. :disappointed:

I hope that I have corrected it in my last commit. If possible, please try again.

Jul 12 '23 20:07 starypatyk

Thanks! A quick test was succesful with the updated pull and as fast as the previous approach. Tested with and without File access control. I'm just on my mobile, thus a bit limited with testing. I will collect some logs today or tomorrow to verify that everything looks as expected.

Jul 13 '23 04:07 XueSheng-GIT

Here are the logs using the latest pull on NC 27.0.0 with File access control enabled (same webdav search as before https://github.com/nextcloud/server/pull/37061#issuecomment-1633013375).

pgsql query log: webdav-search_patched-4.log

nextcloud log: nextcloud_patched-4.log

Search speed is still amazing (same as with previous version of the pull). I was not able to see a difference with/without File access control enabled.

I've also applied this patch to one of my production systems (NC 26.0.3). At least initial testing went fine so far.

@starypatyk, thanks again for your effort! Hope that this will find its way to a stable release. Just let me know if you need further testing/logs from my side.

EDIT: Forgot to mention and maybe it's obvious, but unified search of the web interface is now fast too! This used to time out on my test instance (>60s). Now the results are shown within 1-2s.

Jul 13 '23 17:07 XueSheng-GIT

Hi @XueSheng-GIT,

Thanks for your testing and for the logs. :+1: Good to know that my changes help.

I now need to do some clean-up before submitting it for final review.

Jul 13 '23 19:07 starypatyk

Hi @AndyScherzinger, @come-nc, @icewind1991,

After conversation with @XueSheng-GIT, I have updated this PR recently. It seems that these changes can provide even greater performance improvements is some cases - see e.g.: https://github.com/nextcloud/server/issues/35776#issuecomment-1627617345

Would you be able to review my changes again?

I have changed the approach slightly - currently I post-process the queries generated by getQueryFilterForStorage() calls.

I tried to put the optimization code in an additional QueryOptimizerStep in the existing QueryOptimizer code, but I was not happy with the result. The code to find the original storage/path conditions was quite awkward and complex. Doing this directly after obtaining the storageFilters seemed more natural: https://github.com/nextcloud/server/blob/2987c0d290c5e4b535b1f4173c3ca57c3b0fc6c4/lib/private/Files/Cache/QuerySearchHelper.php#L154

I do not plan any more changes, unless there are additional suggestions from the review.

There are a few additional topics that I think could be addressed in follow-up PRs:

This might break on Oracle when the IN list gets longer than 1000 items. I do not know if it is better to always split the list here when generating the query tree, or in the QueryBuilder specific for Oracle: https://github.com/nextcloud/server/blob/ca9d6db6526b976eccaf4eb82d4f656f9608691a/lib/private/DB/QueryBuilder/ExpressionBuilder/OCIExpressionBuilder.php#L121
There is a related issue #38653. At first sight my optimizations will not help in this case. But it seems quite straightforward to include additional optimization for this case in the same manner.
I am not sure how my changes interfere with the QueryOptimizer.

Jul 14 '23 21:07 starypatyk

Hi @come-nc,

Could you also test the opposite case, for a search with not a lot of shared files, which is currently fast (<1s), does your PR add visible overhead?

I have not been able to measure the overhead. In my "production" environment I have a lot of shared files, so this does not apply. When I tried to measure differences in my dev environment with no shared files, variation of timing between the runs (100-140 ms) was much higher than the difference between original code and my PR (~ 1 ms).

When there are no shared files the query should not be modified at all by my optimization code, so query execution time should not be affected.

Regarding time required to perform the optimization itself - this is an in-memory operation that should grow roughly linearly with the number of shares. So, even with thousands of shares should be negligible compared to the query execution time.

Jul 18 '23 21:07 starypatyk

I've started implementing something similar but at a level lower and more generalized: https://github.com/nextcloud/server/pull/40555

It applies similar transformations on the search operation before building the db query.

Sep 21 '23 12:09 icewind1991

@icewind1991

I've started implementing something similar but at a level lower and more generalized: #40555

It applies similar transformations on the search operation before building the db query.

Looks great. :+1: I will close this PR when #40555 is merged.

Sep 25 '23 19:09 starypatyk

Looks great. 👍 I will close this PR when #40555 is merged.

#40555 is merged.

Feb 23 '24 18:02 skjnldsv