OwnCloud not responsive because of inaccessible federated share #22987

Closed
atroxix opened this Issue Mar 9, 2016 · 26 comments

Projects

None yet

8 participants

@atroxix
atroxix commented Mar 9, 2016

Steps to reproduce

  1. Add/accept share from a remote OwnCloud server
  2. Make the remote OwnCloud server inaccessible

Expected behaviour

Remote files should not be shown, no timeouts should occur etc.

Actual behaviour

I quite cannot use OwnCloud at all. After quite some time (10min or so) I finally get a list of my files, but every step is evenly slow. In owncloud.log I have those lines:

{"reqId":"1SZoqoBqU+bZ7KvYql4B","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(https://inaccessible-owncloud.server//status.php): failed to open stream: php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at /srv/www/owncloud/apps/files_sharing/lib/external/storage.php#260","level":3,"time":"2016-03-09T07:14:56+00:00"}

After disabling files_external with occ, it's still the same (the log lines too).

Server configuration

Operating system: FreeBSD

Web server: Apache 2.4

Database: MariaDB 10.0

PHP version: 5.6

ownCloud version: 9.0.0

Updated from an older ownCloud or fresh install: Updated

Where did you install ownCloud from: FreeBSD ports (first upgraded to 9.0.0RC1 manually)

Signing status (ownCloud 9.0 and above):

Login as admin user into your ownCloud and access 
http://example.com/index.php/settings/integrity/failed 
paste the results here.

After 10 minute wait:

No errors have been found.

List of activated apps:

The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php
Enabled:
  - activity: 2.2.1
  - comments: 0.2
  - dav: 0.1.5
  - federatedfilesharing: 0.1.0
  - federation: 0.0.4
  - files: 1.4.4
  - files_pdfviewer: 0.8
  - files_sharing: 0.9.1
  - files_texteditor: 2.1
  - files_trashbin: 0.8.0
  - files_versions: 1.2.0
  - files_videoplayer: 0.9.8
  - firstrunwizard: 1.1
  - notifications: 0.2.3
  - provisioning_api: 0.4.1
  - systemtags: 0.2
  - templateeditor: true
  - updatenotification: 0.1.0
Disabled:
  - encryption
  - external
  - files_external
  - gallery
  - user_external
  - user_ldap

The content of config/config.php:

The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php
{
    "system": {
        "instanceid": "occ40e4dc891",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "\/srv\/www\/owncloud_data",
        "dbtype": "mysql",
        "version": "9.0.0.19",
        "dbname": "owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "theme": "",
        "trusted_domains": [
            "myserv.fqdn",
            "myserv.myhost.local",
            "myserv.local"
        ],
        "forcessl": false,
        "mail_smtpmode": "php",
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "updatechecker": false,
        "secret": "***REMOVED SENSITIVE VALUE***",
        "singleuser": false,
        "loglevel": 2,
        "maintenance": false,
        "appstore.experimental.enabled": false,
        "trashbin_retention_obligation": "auto"
    }
}

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

Client configuration

Browser: Chromium
Firefox cannot even log in (login form is prompted again).

Operating system: Linux/Windows

Logs

Web server error log

(nothing)

ownCloud log (data/owncloud.log)

{"reqId":"lZUvUDGg3f7N9ESoXTrV","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(): php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:25+00:00"}
{"reqId":"lZUvUDGg3f7N9ESoXTrV","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(https:\/\/inaccessible-owncloud.server\/\/status.php): failed to open stream: php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:25+00:00"}
{"reqId":"bUfJ+QW6Ll3kWCPQA4s5","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(): php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:29+00:00"}
{"reqId":"bUfJ+QW6Ll3kWCPQA4s5","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(https:\/\/inaccessible-owncloud.server\/\/status.php): failed to open stream: php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:29+00:00"}
{"reqId":"b\/OYAE985xSetToxrNQr","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(): php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:30+00:00"}
{"reqId":"b\/OYAE985xSetToxrNQr","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(https:\/\/inaccessible-owncloud.server\/\/status.php): failed to open stream: php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:30+00:00"}
{"reqId":"FaqTsTGuCzcZ9AtPCqAk","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(): php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:52+00:00"}
{"reqId":"FaqTsTGuCzcZ9AtPCqAk","remoteAddr":"10.0.254.102","app":"PHP","message":"file_get_contents(https:\/\/inaccessible-owncloud.server\/\/status.php): failed to open stream: php_network_getaddresses: getaddrinfo failed: hostname nor servname provided, or not known at \/srv\/www\/owncloud\/apps\/files_sharing\/lib\/external\/storage.php#260","level":3,"time":"2016-03-09T07:37:52+00:00"}

Browser log

N/A
@LukasReschke LukasReschke added the bug label Mar 9, 2016
@LukasReschke LukasReschke added this to the 9.0.1-current-maintenance milestone Mar 9, 2016
@LukasReschke
Member

Can you try the patch from #22974 as well as configure a local memory cache? THX.

https://github.com/owncloud/core/blob/master/config/config.sample.php#L894-L899

@LukasReschke
Member

https://inaccessible-owncloud.server//status.php

FTR: This error message will be gone with #22972. Won't fix the bug but at least reduces the noise.

@LukasReschke LukasReschke changed the title from OwnCloud not responsive because of federated share to OwnCloud not responsive because of inaccessible federated share Mar 9, 2016
@atroxix
atroxix commented Mar 9, 2016
  1. Applied patch from #22974 - no change
  2. Applied patch from #22972 - no change (and I still get those errors in owncloud.log, but maybe not so many)
  3. Added memcache.local - no change
  4. Applied patch from #22855 (scanner.php part only) - OwnCloud started responding again

Is there a way I could remove (un-accept them) those remote shares from my OwnCloud somehow?

I also noticed new errors:

{"reqId":"KSvIvV7DwMK334yzC+dB","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:12:07+00:00"}
{"reqId":"ZAewHoezxXmcZWlI+Gsh","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:12:50+00:00"}
{"reqId":"LSXzvNufGB5MuWue0D59","remoteAddr":"10.0.254.102","app":"PHP","message":"Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server at \/srv\/www\/owncloud\/3rdparty\/sabre\/http\/lib\/Client.php#356","level":3,"time":"2016-03-09T09:13:38+00:00"}
{"reqId":"8fngDnG8j4EUFTJjs3wR","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:15:08+00:00"}
{"reqId":"OxfRcFHsEVGIAM5O3xzz","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:15:51+00:00"}
{"reqId":"iytsLGJjnhluI85OV2Cz","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:17:11+00:00"}
@LukasReschke
Member

Added memcache.local - no change

Did you apply memcache local together with #22974?

@atroxix
atroxix commented Mar 9, 2016

I applied all those listed changed in sequence and did not revert anything after any of those. So yes, when I added memcache.local patch from #22974 was already in place.

@LukasReschke LukasReschke added a commit that referenced this issue Mar 9, 2016
@LukasReschke LukasReschke Delay check till scanner is used
Fixes #22973 and #22987
4ccbac8
@LukasReschke
Member

Interesting. What memory cache do you use? That should not happen.

Anyways, please test #22998. That should hopefully solve your problem.

@atroxix
atroxix commented Mar 9, 2016

I added APCu cache module.

Got scanner.php from #22998, but there are still those errors about scanning...

{"reqId":"qJf7Nngjr2C6iK9NRnQD","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:47:37+00:00"}
{"reqId":"VQYsiweJAmR0dupbxJJW","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:48:21+00:00"}
{"reqId":"VrBK1xG3bJkx46jtARyc","remoteAddr":"10.0.254.102","app":"core","message":"Exception while scanning storage \"shared::0834fb19a1db5e6deca1117a75491c65\": Sabre\\HTTP\\ClientException: Could not resolve host: inaccessible-owncloud.server","level":3,"time":"2016-03-09T09:50:29+00:00"}

And how about being able to remove those remote shares from my list altogether?

@LukasReschke
Member

And how about being able to remove those remote shares from my list altogether?

Just for the record, is your ownCloud accessible again after #22998? If yes please open a new bug report about removing invalid remote shares :)

@atroxix
atroxix commented Mar 9, 2016

It was accessible also after applying patch from #22855.

Bug report about removing invalid remote shares: #23005.

@LukasReschke
Member

It was accessible also after applying patch from #22855.

Please revert #22855, we can't take this as it breaks other stuff. I'd be interested whether #22998 works for you.

It should hopefully work for you and do the same but not break other stuff.

@atroxix
atroxix commented Mar 9, 2016

It seems I missed applying storage.php changes from #22855, and as I downloaded the whole scanner.php from #22998, it effectively overwrote scanner.php changes from #22855 too.

So yes, changes from #22855 are reverted and #22998 is applied.

@atroxix
atroxix commented Mar 9, 2016

BTW, although I can login to web UI and see my files, OwnCloud client seems to be not able to finish its job, ie. it's constantly checking for changes, but doesn't do anything besides this.

@LukasReschke
Member

@atroxix Can you press F12 in the open client to open the log window or use --logwindow when starting? What does it say there?

@atroxix
atroxix commented Mar 9, 2016

Many "cannot connect" messages besides things that seem to be normal:

$ grep -i 'cannot connect' owncloud.log 
03-09 12:48:22:494 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:23:267 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:24:130 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:24:676 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:25:247 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:26:172 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:26:715 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:27:246 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:28:042 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:28:604 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:29:386 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:29:946 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:30:502 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:31:444 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:32:021 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:33:167 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:33:812 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:33:825 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:34:406 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:35:198 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:35:743 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:36:414 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:36:974 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:37:806 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:38:364 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
03-09 12:48:38:926 10792 unknown: QObject::connect: Cannot connect (null)::stateChanged(QNetworkSession::State) to QNetworkReplyHttpImpl::_q_networkSessionStateChanged(QNetworkSession::State)
@LukasReschke
Member

@owncloud/desktop-developers Any idea what causes this error? Can it be caused by a server bug or is that totally client related?

@LukasReschke LukasReschke reopened this Mar 9, 2016
@guruz
Contributor
guruz commented Mar 9, 2016

@LukasReschke The QObject::connect: Cannot connect is related to having an old Qt version, it is about object connections not network connections. If I remember correctly it is not making anything break. For some reason I don't see it in https://github.com/owncloud/client/tree/master/admin/qt/patches but Qt 5.6 should have this fixed.

@atroxix
atroxix commented Mar 9, 2016

It seems that this client issue is something else - it now started syncing basically all my files... maybe related to the fact that it timed out before?

@LukasReschke LukasReschke added a commit that referenced this issue Mar 9, 2016
@LukasReschke LukasReschke Delay check till scanner is used
Fixes #22973 and #22987
80b9126
@oparoz
Contributor
oparoz commented Mar 9, 2016

I got hit by a similar bug.

A federated share on stable8.1 wasn't available any more (no idea if that was legitimate or not).
getstoragstats.php started to return 503s "Exception":"OCP\Files\StorageNotAvailableException".

and the big problem is that Files stops working properly, but still does kind of work.

  • share ID is missing on row
  • share dialogue says share cannot be reshared
  • Thumbnails are shown properly, both on the row and in details view
  • Login in/out doesn't change anything

In the browser log, I can see that share.js is not happy.

It came back after a few minutes, but a beginner user would be lost.

Would be great is the share could be marked as unavailable and the share button/dialogue disabled.

@oparoz
Contributor
oparoz commented Mar 9, 2016

I'll open a new bug because I can make sharing break in a couple of clicks...

@PVince81
Collaborator

Here is @oparoz's ticket #23057 and is not related to this issue.

@atroxix @LukasReschke if the responsiveness problem is solved, can we close this ticket ?

If needed, the discussion about the client redownloading after timeout should be discussed in a separate ticket. Thanks.

@atroxix
atroxix commented Mar 14, 2016

Yes, this problem is solved for me.

@atroxix atroxix closed this Mar 14, 2016
@LukasReschke LukasReschke added a commit that referenced this issue Mar 15, 2016
@LukasReschke LukasReschke Delay check till scanner is used
Fixes #22973 and #22987
987146d
@atroxix
atroxix commented Mar 17, 2016

BTW, I just tried upgrade again from 8.2 to 9.0 with all the changes applied to it, but the external share still causes UI to be very-very slow (waiting for timeout or something). When I remove the line from oc_share_external table it becomes responsive again.

@rullzer
Contributor
rullzer commented Mar 17, 2016

@atroxix yeah that is to be expected. but are all your shares still there?

@atroxix
atroxix commented Mar 17, 2016

OK. Commenting about my shared under the other issue ;)

@Ark74
Ark74 commented Apr 12, 2016

I've fix a similar issue with a shared file on a external server gone down. @atroxix comment, help my with this issue.
Offtopic: BTW, upgrading from 8.2 to 9.0 its not a really smooth process.

@hoax89
hoax89 commented May 31, 2016

@LukasReschke just out of curiosity, what gets cached that this unresponsiveness (2min+ load time) is eliminated? Also, maybe consider making the memory cache warning more present, right now it feels like "oh, if you want a few nanoseconds performance increase here and there, consider using memory caching", but in the case of an inaccessible federated share it actually makes a completely unusable ownCloud usable again.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment