files_sharing makes TTFB take ~2 minutes #7001

enoch85 · 2017-10-29T13:21:09Z

Steps to reproduce

Have a lot of shares (like 200 maybe) mixed link and federated
Notice that TTFB is 2 minutes
Investigate why
Disable files_sharing
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) ...

The text was updated successfully, but these errors were encountered:

jospoortvliet · 2017-10-30T12:12:37Z

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 · 2017-10-30T15:47:05Z

cc @nextcloud/sharing

enoch85 · 2017-10-30T20:04:40Z

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 · 2017-11-14T21:31:15Z

Any update here?

Just got this:

enoch85 · 2017-11-16T22:33:48Z

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 · 2017-11-16T23:21:58Z

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 · 2017-11-17T00:12:54Z

Some more info after some cleanup:

'

enoch85 · 2017-11-17T00:44:35Z

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

enoch85 · 2017-11-17T00:54:28Z

cc @nextcloud/sharing

enoch85 · 2017-11-27T16:00:26Z

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

MorrisJobke · 2017-11-27T16:45:11Z

@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 · 2017-11-27T17:14:33Z

@MorrisJobke Sure! How do we proceed?

MorrisJobke · 2017-11-27T17:55:34Z

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 · 2017-11-27T18:04:58Z

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 · 2017-12-05T13:07:55Z

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 · 2017-12-13T12:00:56Z

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 · 2017-12-13T20:34:29Z

@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 · 2017-12-13T21:22:26Z

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 · 2017-12-13T21:29:35Z

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

MorrisJobke · 2017-12-13T21:30:16Z

@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 · 2017-12-13T21:30:49Z

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

enoch85 · 2017-12-13T22:11:45Z

Wow, it works. Thanks a ton guys!

9662 · 2018-03-09T15:07:10Z

@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 · 2018-03-09T15:08:56Z

@9662 do you have a memcache configured?

9662 · 2018-03-09T15:09:57Z

@rullzer

Not on this instance, no.

rullzer · 2018-03-09T15:18:10Z

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

9662 · 2018-03-09T15:18:47Z

What about using Redis instead?

rullzer · 2018-03-09T15:19:43Z

Also fine

9662 · 2018-03-09T15:47:28Z

Working fine now. Vielen Dank!

enoch85 added feature: sharing bug labels Oct 29, 2017

MorrisJobke added the high label Nov 27, 2017

MorrisJobke added this to the Nextcloud 13 milestone Dec 13, 2017

rullzer mentioned this issue Dec 13, 2017

Also cache invalid DiscoveryService response #7485

Merged

rullzer closed this as completed in #7485 Dec 14, 2017

enoch85 mentioned this issue Dec 14, 2017

Improve handling of invalid federated (and regular) shares #7513

Open

MorrisJobke mentioned this issue Dec 17, 2017

Everything is slow when php is restarted or an apps activated since update 12.0.4 #7440

Closed

MorrisJobke mentioned this issue Dec 18, 2017

Offline federated share causes slow down and cannot be removed #2638

Closed

krombel mentioned this issue Dec 29, 2017

Not-Accessible remote share causes high slowdowns (and timeouts) #7645

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

files_sharing makes TTFB take ~2 minutes #7001

files_sharing makes TTFB take ~2 minutes #7001

enoch85 commented Oct 29, 2017 •

edited

Loading

jospoortvliet commented Oct 30, 2017 •

edited

Loading

MorrisJobke commented Oct 30, 2017

enoch85 commented Oct 30, 2017

enoch85 commented Nov 14, 2017

enoch85 commented Nov 16, 2017 •

edited

Loading

enoch85 commented Nov 16, 2017

enoch85 commented Nov 17, 2017

enoch85 commented Nov 17, 2017

enoch85 commented Nov 17, 2017

enoch85 commented Nov 27, 2017

MorrisJobke commented Nov 27, 2017

enoch85 commented Nov 27, 2017

MorrisJobke commented Nov 27, 2017

enoch85 commented Nov 27, 2017

enoch85 commented Dec 5, 2017

jospoortvliet commented Dec 13, 2017 •

edited

Loading

enoch85 commented Dec 13, 2017 •

edited

Loading

enoch85 commented Dec 13, 2017

MorrisJobke commented Dec 13, 2017

MorrisJobke commented Dec 13, 2017

enoch85 commented Dec 13, 2017

enoch85 commented Dec 13, 2017

9662 commented Mar 9, 2018

rullzer commented Mar 9, 2018

9662 commented Mar 9, 2018

rullzer commented Mar 9, 2018

9662 commented Mar 9, 2018

rullzer commented Mar 9, 2018

9662 commented Mar 9, 2018

files_sharing makes TTFB take ~2 minutes #7001

files_sharing makes TTFB take ~2 minutes #7001

Comments

enoch85 commented Oct 29, 2017 • edited Loading

Steps to reproduce

Expected behaviour

Actual behaviour

General server configuration

Nextcloud configuration

Client configuration

Logs

jospoortvliet commented Oct 30, 2017 • edited Loading

MorrisJobke commented Oct 30, 2017

enoch85 commented Oct 30, 2017

enoch85 commented Nov 14, 2017

enoch85 commented Nov 16, 2017 • edited Loading

enoch85 commented Nov 16, 2017

enoch85 commented Nov 17, 2017

enoch85 commented Nov 17, 2017

enoch85 commented Nov 17, 2017

enoch85 commented Nov 27, 2017

MorrisJobke commented Nov 27, 2017

enoch85 commented Nov 27, 2017

MorrisJobke commented Nov 27, 2017

enoch85 commented Nov 27, 2017

enoch85 commented Dec 5, 2017

jospoortvliet commented Dec 13, 2017 • edited Loading

enoch85 commented Dec 13, 2017 • edited Loading

enoch85 commented Dec 13, 2017

MorrisJobke commented Dec 13, 2017

MorrisJobke commented Dec 13, 2017

enoch85 commented Dec 13, 2017

enoch85 commented Dec 13, 2017

9662 commented Mar 9, 2018

rullzer commented Mar 9, 2018

9662 commented Mar 9, 2018

rullzer commented Mar 9, 2018

9662 commented Mar 9, 2018

rullzer commented Mar 9, 2018

9662 commented Mar 9, 2018

enoch85 commented Oct 29, 2017 •

edited

Loading

jospoortvliet commented Oct 30, 2017 •

edited

Loading

enoch85 commented Nov 16, 2017 •

edited

Loading

jospoortvliet commented Dec 13, 2017 •

edited

Loading

enoch85 commented Dec 13, 2017 •

edited

Loading