Server: files_sharing makes TTFB take ~2 minutes

[enoch85]

Steps to reproduce

1. Have a lot of shares (like 200 maybe) mixed link and federated
2. Notice that TTFB is 2 minutes
3. Investigate why
4. Disable files_sharing
5. Notice how Nextcloud flies and TTFB is 5 ms.

Expected behaviour

TTFB should be quick even with many shared links and federated shares.

Actual behaviour

As soon as File Sharing is activated (the app) TTFB is around 2 minutes and sometimes more.

I also tried with changing to Nginx because I thought it was an Apache error, but Nginx timed out because it took such a long time. When I increased the timeout for PHP-FPM the end result was the same, around 2 minutes.

Other than that I check PostgreSQL (that was the first thing I thought was the cause) but after talking to some DB experts that helped me do some digging, we found that PostgreSQL is not the error, everything is superfast there.

I also tried to disable most of the federated shares, but it didn't help much.

Also, the "worst" user is my own, becuase I have the most shared links. It's slow for other users as well, but not even close to 2 minutes. Around 30 seconds.

cc @jospoortvliet for the same issue as me.

General server configuration

Operating system: Linux domain.techandme.se 4.4.0-97-generic #120-Ubuntu SMP Tue Sep 19 17:28:18 UTC 2017 x86_64

Web server: Apache/2.4.18 (Ubuntu) (apache2handler)

Database: pgsql PostgreSQL 9.6.5 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 5.4.0-6ubuntu1~16.04.4) 5.4.0 20160609, 64-bit

PHP version: 7.0.22-0ubuntu0.16.04.1

PHP-modules loaded

 - Core
 - date
 - libxml
 - openssl
 - pcre
 - zlib
 - filter
 - hash
 - Reflection
 - SPL
 - session
 - standard
 - apache2handler
 - PDO
 - xml
 - calendar
 - ctype
 - curl
 - dom
 - mbstring
 - fileinfo
 - ftp
 - gd
 - gettext
 - iconv
 - imap
 - intl
 - json
 - ldap
 - exif
 - mcrypt
 - pdo_pgsql
 - pdo_sqlite
 - pgsql
 - Phar
 - posix
 - readline
 - redis
 - shmop
 - SimpleXML
 - smbclient
 - sockets
 - sqlite3
 - sysvmsg
 - sysvsem
 - sysvshm
 - tokenizer
 - wddx
 - xmlreader
 - xmlwriter
 - xsl
 - zip
 - libsmbclient
 - Zend OPcache

Nextcloud configuration

Nextcloud version: 12.0.3 - 12.0.3.3

Updated from an older Nextcloud/ownCloud or fresh install: Updated

Where did you install Nextcloud from: Nextcloud.com

Are you using external storage, if yes which one: no

Are you using encryption: no

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

Signing status

[]

Enabled apps

 - activity: 2.5.2
 - admin_notifications: 1.0.0
 - bruteforcesettings: 1.0.2
 - calendar: 1.5.5
 - checksum: 0.3.5
 - comments: 1.2.0
 - contacts: 2.0.1
 - dav: 1.3.0
 - federatedfilesharing: 1.2.0
 - federation: 1.2.0
 - files: 1.7.2
 - files_downloadactivity: 1.1.1
 - files_external: 1.3.0
 - 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
 - impersonate: 1.0.1
 - issuetemplate: 0.2.2
 - logreader: 2.0.0
 - lookup_server_connector: 1.0.0
 - mail: 0.7.3
 - nextcloud_announcements: 1.1
 - notes: 2.3.1
 - notifications: 2.0.0
 - oauth2: 1.0.5
 - ocsms: 1.12.1
 - password_policy: 1.2.2
 - previewgenerator: 1.0.7
 - provisioning_api: 1.2.0
 - qownnotesapi: 17.5.0
 - richdocuments: 1.12.35
 - serverinfo: 1.2.0
 - sharebymail: 1.2.0
 - socialsharing_diaspora: 1.0.1
 - socialsharing_email: 1.0.1
 - socialsharing_facebook: 1.0.1
 - socialsharing_googleplus: 1.0.1
 - socialsharing_twitter: 1.0.1
 - spreed: 2.0.1
 - survey_client: 1.0.0
 - systemtags: 1.2.0
 - theming: 1.3.0
 - twofactor_backupcodes: 1.1.1
 - twofactor_totp: 1.3.1
 - updatenotification: 1.2.0
 - workflowengine: 1.2.0

Disabled apps

 - admin_audit
 - encryption
 - user_external
 - user_ldap

Content of config/config.php

{
    "updatechecker": false,
    "passwordsalt": "***REMOVED SENSITIVE VALUE***",
    "secret": "***REMOVED SENSITIVE VALUE***",
    "trusted_domains": [
        "localhost",
        "192.168.4.111",
        "domain.techandme.se",
        "domain1.techandme.se"
    ],
    "datadirectory": "\/var\/ncdata",
    "overwrite.cli.url": "https:\/\/domain.techandme.se\/",
    "dbtype": "pgsql",
    "version": "12.0.3.3",
    "dbname": "***REMOVED SENSITIVE VALUE***",
    "dbhost": "127.0.0.1",
    "dbtableprefix": "oc_",
    "dbuser": "***REMOVED SENSITIVE VALUE***",
    "dbpassword": "***REMOVED SENSITIVE VALUE***",
    "logtimezone": "Europe\/Stockholm",
    "installed": true,
    "instanceid": "oc7aii0tkiol",
    "mail_smtpmode": "smtp",
    "mail_smtpauth": 1,
    "mail_smtpport": "587",
    "mail_smtphost": "mail.citynetwork.se",
    "mail_smtpauthtype": "LOGIN",
    "mail_from_address": "***REMOVED SENSITIVE VALUE***",
    "mail_domain": "techandme.se",
    "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
    "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
    "allowZipDownload": true,
    "session_lifetime": 1800,
    "forcessl": true,
    "logfile": "\/var\/log\/nfs-share\/nextcloud.log",
    "loglevel": 2,
    "memcache.local": "\\OC\\Memcache\\Redis",
    "filelocking.enabled": true,
    "memcache.distributed": "\\OC\\Memcache\\Redis",
    "memcache.locking": "\\OC\\Memcache\\Redis",
    "redis": {
        "host": "\/var\/run\/redis\/redis.sock",
        "port": 0,
        "timeout": 0,
        "dbindex": 0
    },
    "trusted_proxies": [
        [
            "192.168.4.201"
        ]
    ],
    "forwarded_for_headers": [
        "HTTP_X_FORWARDED",
        "HTTP_FORWARDED_FOR"
    ],
    "maintenance": false,
    "mail_smtpsecure": "tls",
    "htaccess.RewriteBase": "\/",
    "theme": "",
    "updater.release.channel": "stable",
    "trashbin_retention_obligation": "auto, 30",
    "activity_expire_days": 60
}

Client configuration

Browser: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/62.0.3202.62 Chrome/62.0.3202.62 Safari/537.36

Operating system: Ubuntu Budgie 17.10

Logs

Web server error log

Insert your webserver log here

Nextcloud log (data/nextcloud.log)

Nothing relevant

Browser log

Insert your browser log here, this could for example include:

a) The javascript console log
b) The network log
c) ...

[jospoortvliet]

Currently my Nc server is down so I can't test this but as soon as I am back home (Nov 9) I'll give it a try, see if disabling the files_sharing app solves the problem. I did try to disable sharing in the admin panel but that didn't help.

There must be a share (or more than one) which causes this extreme slow-down. Might be a (broken?) federated share, perhaps?

[MorrisJobke]

cc @nextcloud/sharing

[enoch85]

There must be a share (or more than one) which causes this extreme slow-down. Might be a (broken?) federated share, perhaps?

Yeah, I think so to. But how do I find it? @MorrisJobke Do you know any good SQL query for PostgreSQL?

[enoch85]

Any update here?

Just got this:

[enoch85]

I suggest that:

• When a URL for the server of a federated share has been inactive (aka 404) for 30 days, then remove the federated share automatically with cron.php. A solution could be to ping the domain of the reviver once a day for example and after 30 days of "reached time out" remove the share to that specific reviver.
• The federated shares are performance checked, so when a federated share performs bad, inform the user with a notification. (As a stage 2 step)
• List all federated share users in the Files app, in addition to "Shared by link". So for example "Federated shares" and list all the users.

@jospoortvliet Have you had any success in finding the cause? I just removed some federated shares, but it still didn't help. :/

[enoch85]

Something is defently wrong with files_sharing:

1510XXXXXXxxx9614 [0 unix:/var/run/redis/redis.sock] "GET" "6334f9a466d0XXXXXXXXXXXX/ocs-discoveryhttps://jvabmolnet.se#FEDERATED_SHARING"
15XXXXXXXXXXXX79698 [0 unix:/var/run/redis/redis.sock] "EXISTS" "6334f9aXXXXXXXXXXXXXb6/ocs-discoveryhttps://jvabmolnet.se#FEDERATED_SHARING"

X = my input.

There is no share with jvabmolnet.se as I removed it. I also did a FLUSHALL on Redis several times.

[enoch85]

Some more info after some cleanup:

'

[enoch85]

How can I remove ALL federated shares from specific folders in one go?

[enoch85]

cc @nextcloud/sharing

[enoch85]

Just tested with 13.0.0beta1 and it's still the same issue. @jospoortvliet Did you manage to solve it?

[MorrisJobke]

@enoch85 Any chance, that we can install the blackfire.io php extension on that machine, set it up with my account and run some profiler on it?

[enoch85]

@MorrisJobke Sure! How do we proceed?

[MorrisJobke]

This is the blackfire profile from the session with @enoch85

https://blackfire.io/profiles/82cf5cfa-4296-4cd7-a09a-e751ad4d447f/graph

There is a federated share that is unavailable:

select * from oc_storages where numeric_id = 45;
                    id                    | numeric_id | available | last_checked
------------------------------------------+------------+-----------+--------------
 shared::8979944323bb262c7830bd591543ec0a |         45 |         0 |   1510879755  

We should not run into timeouts on the files app page load then. The remote server is just not there anymore.

cc @schiessle @icewind1991

[enoch85]

We should not run into timeouts on the files app page load then.

All pages are slow, not just the files app. When turning off files_sharing every page takes like 500 ms or less to load.

[enoch85]

I know you are busy guys, but I would love to se this solved soon. My cloud is unusable since this happened. Please? :) @MorrisJobke @schiessle @icewind1991

[jospoortvliet]

So I just tested Nextcloud 13 Beta 2, disabled the sharing app and - lo and behold - the problem is entirely gone. I had no other issues. Yes, I upgraded my private instance. Without backup. Bite me! 🐶

But after enabling the sharing app - slow again. Back to disabling the sharing app. This is worth fixing asap, I'd say. Not a regression but it makes Nextcloud unusable with federation @schiessle

[enoch85]

@jospoortvliet That the files_sharing is causing it is known since before. :)

This is worth fixing asap, I'd say

I was hoping for 13.0.0, but it seems dark. :( Still, two weeks left I heard, so there is hope! Please?

[enoch85]

I mean if @jospoortvliet and I are affected, there must be several more, but who is not reporting and thinking Nextcloud is crap because of this bug. So, I'd say it's best for reputation to fix this.

[MorrisJobke]

@enoch85 There is a fix since 8 hours in #7485 😉

[MorrisJobke]

@enoch85 There is a fix since 8 hours in #7485 😉

That also means it is not in the beta 3 but maybe in the RC 1 😉

[enoch85]

I hope my emojois are enough to express my gratitude! Must test!

[enoch85]

Wow, it works. Thanks a ton guys!

[9662]

@MorrisJobke @jospoortvliet

I'm afraid I am experiencing these exact symptoms on Nextcloud 13.0.0 (and previously on 13.0.0-RC4, this instance is on the Beta channel).

If I disable the file sharing app then all is good. As soon as I enable it back, there is an ~11 / 12 second gap between requests.

Share type | Instances
--------------|------------
User shares | 48
Links | 6
Federated sent | 0
Federated received | 5

Disabling the Federation app did not make any difference.

I am now trying to determine whether all incoming federated servers are up. This is proving challenging due to the unusably slow performance but I'll update when/if I get new info.

[rullzer]

@9662 do you have a memcache configured?

[9662]

@rullzer

Not on this instance, no.

[rullzer]

Well in that case we don't cache it. Enable APCu (and configure it in config.php) and it should work.

[9662]

What about using Redis instead?

[rullzer]

Also fine

[9662]

Working fine now. Vielen Dank!