owncloud / core

:cloud: ownCloud web server core (Files, DAV, etc.)
https://owncloud.com
GNU Affero General Public License v3.0
8.35k stars 2.06k forks source link

OC 8.1 Heavy Performance Problems with Webinterface and Sync-App #17558

Closed transistor91 closed 8 years ago

transistor91 commented 9 years ago

Steps to reproduce

Normal usage of owncloud

Expected behaviour

Sync Client and/or Webinterface should react fast to uploads of files (small files, max. 3MB).

Actual behaviour

Sync Client generates some errors and take really long time (not useful anymore), webinterface uploads file but progress bar only goes to 90%, upload is finished after some minutes. Mysql process consumes a lot of CPU time. Sometimes (but not always) client reports connection timeouts or OwnCloud reports wrong filesize (but not reproducable!).

Server configuration

Operating system: OpenSuse 13.2

Web server: Apache/2.4.10

Database: mysql Ver 14.14 Distrib 5.6.25, for Linux (x86_64) using EditLine wrapper

PHP version: PHP 5.6.1

ownCloud version: (see ownCloud admin page) 8.1

Updated from an older ownCloud or fresh install: Updated from older owncloud

List of activated apps: all official and pre enabled apps + contacts + calendar

The content of config/config.php:

<?php
$CONFIG = array (
  'instanceid' => '...',
  'passwordsalt' => '...',
  'datadirectory' => '/srv/www/htdocs/oc_data',
  'dbtype' => 'mysql',
  'version' => '8.1.0.8',
  'dbname' => 'owncloud',
  'dbhost' => 'localhost',
  'dbtableprefix' => 'oc_',
  'dbuser' => 'owncloud',
  'dbpassword' => '...',
  'installed' => true,
  'maxZipInputSize' => 0,
  'allowZipDownload' => true,
  'forcessl' => true,
  'theme' => '',
  'maintenance' => false,
  'overwritewebroot' => '/oc',
  'overwrite.cli.url' => '/oc',
  'preview_libreoffice_path' => '/usr/bin/libreoffice',
  'trusted_domains' => 
  array (
    0 => '...',
    1 => '...',
  ),  
  'loglevel' => '1',
  'log_type' => 'syslog',
  'logtimezone' => 'Europe/Berlin',
  'mail_smtpmode' => 'php',
  'secret' => '...',
);

Are you using external storage, if yes which one: local/smb/sftp/... No

Are you using encryption: yes/no No

Are you using an external user-backend, if yes which one: LDAP/ActiveDirectory/Webdav/... No

Client configuration

Browser: Firefox, 38.0.6

Operating system: OpenSuse

Logs

Web server error log

[Fri Jul 10 12:24:15.611668 2015] [mpm_prefork:notice] [pid 1031] AH00163: Apache/2.4.10 (Linux/SUSE) OpenSSL/1.0.1k-fips configured -- resuming normal operations
[Fri Jul 10 12:24:15.731111 2015] [core:notice] [pid 1031] AH00094: Command line: '/usr/sbin/httpd2-prefork -f /etc/apache2/httpd.conf -D SSL -D SYSTEMD -D FOREGROUND'
[Fri Jul 10 12:49:58.391066 2015] [core:notice] [pid 1031] AH00052: child pid 1707 exit signal Segmentation fault (11)
[Fri Jul 10 12:52:18.546060 2015] [core:notice] [pid 1031] AH00052: child pid 1706 exit signal Segmentation fault (11)

ownCloud log (data/owncloud.log)

2015-07-10T12:28:08.646500+02:00 my-owncloud ownCloud[1707]: {no app in context} Encryption module "" not found, file will be stored unencrypted (Module with id: OC_DEFAULT_MODULE does not exist.)
2015-07-10T12:30:03.335392+02:00 my-owncloud ownCloud[3520]: {PHP} Undefined index: REQUEST_URI at /srv/www/htdocs/oc/apps/contacts/appinfo/app.php#35
2015-07-10T12:30:08.909672+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "IMG_20150608_111443.jpg" from trash bin because it is older than 30
2015-07-10T12:30:10.033020+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "IMG_20150608_111445.jpg" from trash bin because it is older than 30
2015-07-10T12:30:10.759300+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "TI.l##" from trash bin because it is older than 30
2015-07-10T12:30:11.336722+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "TI.l##" from trash bin because it is older than 30
2015-07-10T12:30:13.523102+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.b##" from trash bin because it is older than 30
2015-07-10T12:30:15.544532+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.s##" from trash bin because it is older than 30
2015-07-10T12:30:16.245408+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.b##" from trash bin because it is older than 30
2015-07-10T12:30:16.930017+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.s##" from trash bin because it is older than 30
2015-07-10T12:30:17.615748+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.b##" from trash bin because it is older than 30
2015-07-10T12:30:18.191826+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.s##" from trash bin because it is older than 30
2015-07-10T12:30:18.934518+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.b##" from trash bin because it is older than 30
2015-07-10T12:30:19.568976+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.s##" from trash bin because it is older than 30
2015-07-10T12:30:25.882842+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.b##" from trash bin because it is older than 30
2015-07-10T12:30:32.004572+02:00 my-owncloud ownCloud[3520]: {files_trashbin} remove "Baseboard_V2.s##" from trash bin because it is older than 30
2015-07-10T12:33:10.027169+02:00 my-owncloud ownCloud[1708]: {PHP} Array to string conversion at /srv/www/htdocs/oc/lib/private/template/functions.php#36
2015-07-10T12:36:00.321933+02:00 my-owncloud ownCloud[2575]: {core} No update found at the ownCloud appstore for app 166049
2015-07-10T12:36:00.782670+02:00 my-owncloud ownCloud[2575]: {core} No update found at the ownCloud appstore for app 166051
2015-07-10T12:36:00.903684+02:00 my-owncloud ownCloud[2575]: {core} No update found at the ownCloud appstore for app 166055
2015-07-10T12:36:01.011004+02:00 my-owncloud ownCloud[2575]: {core} No update found at the ownCloud appstore for app 166048
2015-07-10T12:36:18.830524+02:00 my-owncloud ownCloud[1308]: {index} Exception: {"Exception":"Symfony\\Component\\Routing\\Exception\\RouteNotFoundException","Message":"Unable to generate a URL for the named route \"calendar_index\" as such route does not exist.","Code":0,"Trace":"#0 \/srv\/www\/htdocs\/oc\/lib\/private\/route\/router.php(306): Symfony\\Component\\Routing\\Generator\\UrlGenerator->generate('calendar_index', Array, false)\n#1 \/srv\/www\/htdocs\/oc\/lib\/private\/urlgenerator.php(65): OC\\Route\\Router->generate('calendar_index', Array)\n#2 \/srv\/www\/htdocs\/oc\/lib\/private\/helper.php(139): OC\\URLGenerator->linkToRoute('calendar_index', Array)\n#3 \/srv\/www\/htdocs\/oc\/lib\/public\/util.php(306): OC_Helper::linkToRoute('calendar_index', Array)\n#4 \/srv\/www\/htdocs\/oc\/apps\/calendar\/appinfo\/app.php(30): OCP\\Util::linkToRoute('calendar_index')\n#5 \/srv\/www\/htdocs\/oc\/lib\/private\/app.php(389): require('\/srv\/www\/htdocs...')\n#6 \/srv\/www\/htdocs\/oc\/settings\/ajax\/navigationdetect.php(29): OC_App::getAppNavigationEntries('calendar')\n#7 \/srv\/www\/htdocs\/oc\/lib\/private\/route\/route.php(154) : runtime-created function(1): require_once('\/srv\/www\/htdocs...')\n#8 [internal function]: __lambda_func(Array)\n#9 \/srv\/www\/htdocs\/oc\/lib\/private\/route\/router.php(274): call_user_func('\\x00lambda_1072', Array)\n#10 \/srv\/www\/htdocs\/oc\/lib\/base.php(867): OC\\Route\\Router->match('\/settings\/ajax\/...')\n#11 \/srv\/www\/htdocs\/oc\/index.php(40): OC::handleRequest()\n#12 {main}","File":"\/srv\/www\/htdocs\/oc\/3rdparty\/symfony\/routing\/Symfony\/Component\/Routing\/Generator\/UrlGenerator.php","Line":134}
2015-07-10T12:36:21.675018+02:00 my-owncloud ownCloud[1607]: {index} Exception: {"Exception":"Symfony\\Component\\Routing\\Exception\\RouteNotFoundException","Message":"Unable to generate a URL for the named route \"contacts_index\" as such route does not exist.","Code":0,"Trace":"#0 \/srv\/www\/htdocs\/oc\/lib\/private\/route\/router.php(306): Symfony\\Component\\Routing\\Generator\\UrlGenerator->generate('contacts_index', Array, false)\n#1 \/srv\/www\/htdocs\/oc\/lib\/private\/urlgenerator.php(65): OC\\Route\\Router->generate('contacts_index', Array)\n#2 \/srv\/www\/htdocs\/oc\/lib\/private\/helper.php(139): OC\\URLGenerator->linkToRoute('contacts_index', Array)\n#3 \/srv\/www\/htdocs\/oc\/lib\/public\/util.php(306): OC_Helper::linkToRoute('contacts_index', Array)\n#4 \/srv\/www\/htdocs\/oc\/apps\/contacts\/appinfo\/app.php(18): OCP\\Util::linkToRoute('contacts_index')\n#5 \/srv\/www\/htdocs\/oc\/lib\/private\/app.php(389): require('\/srv\/www\/htdocs...')\n#6 \/srv\/www\/htdocs\/oc\/settings\/ajax\/navigationdetect.php(29): OC_App::getAppNavigationEntries('contacts')\n#7 \/srv\/www\/htdocs\/oc\/lib\/private\/route\/route.php(154) : runtime-created function(1): require_once('\/srv\/www\/htdocs...')\n#8 [internal function]: __lambda_func(Array)\n#9 \/srv\/www\/htdocs\/oc\/lib\/private\/route\/router.php(274): call_user_func('\\x00lambda_760', Array)\n#10 \/srv\/www\/htdocs\/oc\/lib\/base.php(867): OC\\Route\\Router->match('\/settings\/ajax\/...')\n#11 \/srv\/www\/htdocs\/oc\/index.php(40): OC::handleRequest()\n#12 {main}","File":"\/srv\/www\/htdocs\/oc\/3rdparty\/symfony\/routing\/Symfony\/Component\/Routing\/Generator\/UrlGenerator.php","Line":134}
2015-07-10T12:38:31.927751+02:00 my-owncloud ownCloud[1305]: {no app in context} Encryption module "" not found, file will be stored unencrypted (Module with id: OC_DEFAULT_MODULE does not exist.)
2015-07-10T12:47:27.782717+02:00 my-owncloud ownCloud[1309]: {core} No update found at the ownCloud appstore for app 166049
2015-07-10T12:47:28.300087+02:00 my-owncloud ownCloud[1309]: {core} No update found at the ownCloud appstore for app 166051
2015-07-10T12:47:28.435706+02:00 my-owncloud ownCloud[1309]: {core} No update found at the ownCloud appstore for app 166055
2015-07-10T12:47:28.547347+02:00 my-owncloud ownCloud[1309]: {core} No update found at the ownCloud appstore for app 166048

Browser log

karlitschek commented 9 years ago

Can't reproduce here. Everything is snappy. We are constantly working on improving the performance. But without more concrete information there is not a lot that can be done here.

RobinMcCorkell commented 9 years ago

I would strongly suggest investigating those Segmentation faults in Apache, that could be a contributor to the performance issues you are experiencing.

b3nn0 commented 9 years ago

I'm having the exact same issue on an Ubuntu 14.04 server with stock apache: Server version: Apache/2.4.7 (Ubuntu) Server built: Mar 10 2015 13:05:59 Any idea how to debug this further? Anyway, I'm pretty sure that this is not only related to the apache crash, since it is MySQL which uses a lot of CPU time.

EDIT: I just noticed that this only seems to happen when I'm uploading files to a folder that was shared with me. When uploading to my own folders, things seem to work fine.

transistor91 commented 9 years ago

That's the point! Same here. Only folders which are shared with me make the problems (Folder wich I shared with other people works fine for me, for the other people there seems not ro be any problem) . I had a look in oc_tables but there's nothing special. Any suggestions how we can debug this problem? I turned the log level to Everything but nothing appears, same in the apache error log.

I reshared the folder which maked the problems and it works fine again....

b3nn0 commented 9 years ago

Yep, you are right. Un-sharing and then sharing the folders again fixed the problem.

karlitschek commented 9 years ago

@schiesbn any idea? I agree with @Xenopathic Segmentation faults are very bad and could lead indirectly to this problems. I would debug in apache/php what is going on there.

schiessle commented 9 years ago

@transistor91 can you update the "steps to reproduce" ? As I understand your last comment it is something like that:

Further useful information: Does it only happens with the sync client? Does it also happen with the web interface, etc. Please be as precise as possible in the description of "steps to reproduce".

please correct me if it is wrong and update the issue. Thanks!

transistor91 commented 9 years ago

@schiesbn ok, here the steps:

What happen:

Workaround:

Delete Share and share the folder again (User 2 -> User 1), error doesn't appear again.

@karlitschek , @Xenopathic: After using the described workaround I didn't have any Segmentation Faults any more...perhaps the segmentation faults are the result of the problem?

b3nn0 commented 9 years ago

Just to confirm: For me, the problem occurred with the exact same steps. The Folder was shared in 8.0.x, then I upgraded and switched on APCu (and also tried disabling it for verification but it didn't help).

schiessle commented 9 years ago

So we can ignore APCu, it doesn't make a difference. And it only happens with folders shared with oC8.0, right?

b3nn0 commented 9 years ago

I think this can be safely assumed, yes. It worked after unsharung and resharing in 8.1 after all.

b3nn0 commented 9 years ago

I think I have to dismiss my previous assumption. Resharing worked for a while, but today when I was trying to do a larger upload (about 80 photos), the problem came back after the third photo and the upload of the rest is now stalled, while MySQL is constantly eating about ~30% CPU.

Note that this is not a usual "performance" issue that should be "optimized", but a complete stall. Sometimes it just happens that one or two files are actually uploaded, but this is pretty rare.

back2root commented 9 years ago

Hi,

I do see these isues as well on a OC 7.1.0 environment running on CentOS 7. My Apache also logs those Segmentation faults.

I could also capture the following logs that might be interesting:

==> /var/log/httpd/ssl_error_log <==
... PHP Fatal error:  Maximum function nesting level of '100' reached, aborting! in /var/www/html/owncloud/lib/private/legacy/config.php on line 59
... PHP Stack trace:
... PHP   1. {main}() /var/www/html/owncloud/index.php:0
... PHP   2. OC::handleRequest() /var/www/html/owncloud/index.php:40
... PHP   3. OC_Util::setupFS() /var/www/html/owncloud/lib/base.php:866
... PHP   4. OC\\Files\\Filesystem::init() /var/www/html/owncloud/lib/private/util.php:190
... PHP   5. OC\\Files\\Filesystem::initMountPoints() /var/www/html/owncloud/lib/private/files/filesystem.php:350
... PHP   6. OC\\Files\\Config\\MountProviderCollection->getMountsForUser() /var/www/html/owncloud/lib/private/files/filesystem.php:425
... PHP   7. array_reduce() /var/www/html/owncloud/lib/private/files/config/mountprovidercollection.php:62
... PHP   8. OC\\Files\\Config\\MountProviderCollection->OC\\Files\\Config\\{closure}() /var/www/html/owncloud/lib/private/files/config/mountprovidercollection.php:62
... PHP   9. OCA\\Files_Sharing\\MountProvider->getMountsForUser() /var/www/html/owncloud/lib/private/files/config/mountprovidercollection.php:61
... PHP  10. OCP\\Share::getItemsSharedWithUser() /var/www/html/owncloud/apps/files_sharing/lib/mountprovider.php:62
... PHP  11. OC\\Share\\Share::getItemsSharedWithUser() /var/www/html/owncloud/lib/public/share.php:122
... PHP  12. OC\\Share\\Share::getItems() /var/www/html/owncloud/lib/private/share/share.php:305
... PHP  13. OCP\\User::getDisplayName() /var/www/html/owncloud/lib/private/share/share.php:1740
... PHP  14. OC_User::getDisplayName() /var/www/html/owncloud/lib/public/user.php:79

... PHP  15. OC\\User\\Manager->get() /var/www/html/owncloud/lib/private/user.php:447
... PHP  16. OCA\\user_ldap\\USER_LDAP->userExists() /var/www/html/owncloud/lib/private/user/manager.php:132
... PHP  17. OCA\\user_ldap\\lib\\user\\User->update() /var/www/html/owncloud/apps/user_ldap/user_ldap.php:218
... PHP  18. OCA\\user_ldap\\lib\\user\\User->updateAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:133
... PHP  19. OCA\\user_ldap\\lib\\user\\User->setOwnCloudAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:318
... PHP  20. OC\\Avatar->set() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:345
... PHP  21. OC\\Files\\View->unlink() /var/www/html/owncloud/lib/private/avatar.php:118
... PHP  22. OC\\Files\\View->basicOperation() /var/www/html/owncloud/lib/private/files/view.php:600
... PHP  23. OCA\\Files_Trashbin\\Storage->unlink() /var/www/html/owncloud/lib/private/files/view.php:1006
... PHP  24. OCA\\Files_Trashbin\\Storage->doDelete() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:89
... PHP  25. call_user_func_array:{/var/www/html/owncloud/apps/files_trashbin/lib/storage.php:132}() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:132
... PHP  26. OC\\Files\\Storage\\Wrapper\\Encryption->unlink() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:132
... PHP  27. OC\\Encryption\\Util->isExcluded() /var/www/html/owncloud/lib/private/files/storage/wrapper/encryption.php:214
... PHP  28. OC\\User\\Manager->userExists() /var/www/html/owncloud/lib/private/encryption/util.php:374

... PHP  29. OC\\User\\Manager->get() /var/www/html/owncloud/lib/private/user/manager.php:161
... PHP  30. OCA\\user_ldap\\USER_LDAP->userExists() /var/www/html/owncloud/lib/private/user/manager.php:132
... PHP  31. OCA\\user_ldap\\lib\\user\\User->update() /var/www/html/owncloud/apps/user_ldap/user_ldap.php:218
... PHP  32. OCA\\user_ldap\\lib\\user\\User->updateAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:133
... PHP  33. OCA\\user_ldap\\lib\\user\\User->setOwnCloudAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:318
... PHP  34. OC\\Avatar->set() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:345
... PHP  35. OC\\Files\\View->unlink() /var/www/html/owncloud/lib/private/avatar.php:118
... PHP  36. OC\\Files\\View->basicOperation() /var/www/html/owncloud/lib/private/files/view.php:600
... PHP  37. OCA\\Files_Trashbin\\Storage->unlink() /var/www/html/owncloud/lib/private/files/view.php:1006
... PHP  38. OCA\\Files_Trashbin\\Storage->doDelete() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:89
... PHP  39. call_user_func_array:{/var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136}() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  40. OC\\Files\\Storage\\Wrapper\\Encryption->unlink() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  41. OC\\Encryption\\Util->isExcluded() /var/www/html/owncloud/lib/private/files/storage/wrapper/encryption.php:214
... PHP  42. OC\\User\\Manager->userExists() /var/www/html/owncloud/lib/private/encryption/util.php:374

... PHP  43. OC\\User\\Manager->get() /var/www/html/owncloud/lib/private/user/manager.php:161
... PHP  44. OCA\\user_ldap\\USER_LDAP->userExists() /var/www/html/owncloud/lib/private/user/manager.php:132
... PHP  45. OCA\\user_ldap\\lib\\user\\User->update() /var/www/html/owncloud/apps/user_ldap/user_ldap.php:218
... PHP  46. OCA\\user_ldap\\lib\\user\\User->updateAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:133
... PHP  47. OCA\\user_ldap\\lib\\user\\User->setOwnCloudAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:318
... PHP  48. OC\\Avatar->set() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:345
... PHP  49. OC\\Files\\View->unlink() /var/www/html/owncloud/lib/private/avatar.php:118
... PHP  50. OC\\Files\\View->basicOperation() /var/www/html/owncloud/lib/private/files/view.php:600
... PHP  51. OCA\\Files_Trashbin\\Storage->unlink() /var/www/html/owncloud/lib/private/files/view.php:1006
... PHP  52. OCA\\Files_Trashbin\\Storage->doDelete() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:89
... PHP  53. call_user_func_array:{/var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136}() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  54. OC\\Files\\Storage\\Wrapper\\Encryption->unlink() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  55. OC\\Encryption\\Util->isExcluded() /var/www/html/owncloud/lib/private/files/storage/wrapper/encryption.php:214
... PHP  56. OC\\User\\Manager->userExists() /var/www/html/owncloud/lib/private/encryption/util.php:374

... PHP  57. OC\\User\\Manager->get() /var/www/html/owncloud/lib/private/user/manager.php:161
... PHP  58. OCA\\user_ldap\\USER_LDAP->userExists() /var/www/html/owncloud/lib/private/user/manager.php:132
... PHP  59. OCA\\user_ldap\\lib\\user\\User->update() /var/www/html/owncloud/apps/user_ldap/user_ldap.php:218
... PHP  60. OCA\\user_ldap\\lib\\user\\User->updateAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:133
... PHP  61. OCA\\user_ldap\\lib\\user\\User->setOwnCloudAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:318
... PHP  62. OC\\Avatar->set() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:345
... PHP  63. OC\\Files\\View->unlink() /var/www/html/owncloud/lib/private/avatar.php:118
... PHP  64. OC\\Files\\View->basicOperation() /var/www/html/owncloud/lib/private/files/view.php:600
... PHP  65. OCA\\Files_Trashbin\\Storage->unlink() /var/www/html/owncloud/lib/private/files/view.php:1006
... PHP  66. OCA\\Files_Trashbin\\Storage->doDelete() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:89
... PHP  67. call_user_func_array:{/var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136}() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  68. OC\\Files\\Storage\\Wrapper\\Encryption->unlink() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  69. OC\\Encryption\\Util->isExcluded() /var/www/html/owncloud/lib/private/files/storage/wrapper/encryption.php:214
... PHP  70. OC\\User\\Manager->userExists() /var/www/html/owncloud/lib/private/encryption/util.php:374

... PHP  71. OC\\User\\Manager->get() /var/www/html/owncloud/lib/private/user/manager.php:161
... PHP  72. OCA\\user_ldap\\USER_LDAP->userExists() /var/www/html/owncloud/lib/private/user/manager.php:132
... PHP  73. OCA\\user_ldap\\lib\\user\\User->update() /var/www/html/owncloud/apps/user_ldap/user_ldap.php:218
... PHP  74. OCA\\user_ldap\\lib\\user\\User->updateAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:133
... PHP  75. OCA\\user_ldap\\lib\\user\\User->setOwnCloudAvatar() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:318
... PHP  76. OC\\Avatar->set() /var/www/html/owncloud/apps/user_ldap/lib/user/user.php:345
... PHP  77. OC\\Files\\View->unlink() /var/www/html/owncloud/lib/private/avatar.php:118
... PHP  78. OC\\Files\\View->basicOperation() /var/www/html/owncloud/lib/private/files/view.php:600
... PHP  79. OCA\\Files_Trashbin\\Storage->unlink() /var/www/html/owncloud/lib/private/files/view.php:1006
... PHP  80. OCA\\Files_Trashbin\\Storage->doDelete() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:89
... PHP  81. call_user_func_array:{/var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136}() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  82. OC\\Files\\Storage\\Wrapper\\Encryption->unlink() /var/www/html/owncloud/apps/files_trashbin/lib/storage.php:136
... PHP  83. OC\\Encryption\\Util->isExcluded() /var/www/html/owncloud/lib/private/files/storage/wrapper/encryption.php:214
... PHP  84. OC\\User\\Manager->userExists() /var/www/html/owncloud/lib/private/encryption/util.php:374

... PHP  85. OC\\User\\Manager->get() /var/www/html/owncloud/lib/private/user/manager.php:161
... PHP  86. OCA\\user_ldap\\USER_LDAP->userExists() /var/www/html/owncloud/lib/private/user/manager.php:132
... PHP  87. OCA\\user_ldap\\USER_LDAP->userExistsOnLDAP() /var/www/html/owncloud/apps/user_ldap/user_ldap.php:215
... PHP  88. OCA\\user_ldap\\lib\\Access->readAttribute() /var/www/html/owncloud/apps/user_ldap/user_ldap.php:180
... PHP  89. OCA\\user_ldap\\lib\\Access->initPagedSearch() /var/www/html/owncloud/apps/user_ldap/lib/access.php:167
... PHP  90. OCP\\Util::writeLog() /var/www/html/owncloud/apps/user_ldap/lib/access.php:1447
... PHP  91. OC_Log::write() /var/www/html/owncloud/lib/public/util.php:152
... PHP  92. call_user_func:{/var/www/html/owncloud/lib/private/legacy/log.php:66}() /var/www/html/owncloud/lib/private/legacy/log.php:66
... PHP  93. OC\\Log->debug() /var/www/html/owncloud/lib/private/legacy/log.php:66
... PHP  94. OC\\Log->log() /var/www/html/owncloud/lib/private/log.php:163
... PHP  95. call_user_func:{/var/www/html/owncloud/lib/private/log.php:241}() /var/www/html/owncloud/lib/private/log.php:241
... PHP  96. OC_Log_Owncloud::write() /var/www/html/owncloud/lib/private/log.php:241
... PHP  97. OC\\AppFramework\\Http\\Request->getRemoteAddress() /var/www/html/owncloud/lib/private/log/owncloud.php:78
... PHP  98. OC\\AllConfig->getSystemValue() /var/www/html/owncloud/lib/private/appframework/http/request.php:454
... PHP  99. OC\\SystemConfig->getValue() /var/www/html/owncloud/lib/private/allconfig.php:118
RobinMcCorkell commented 9 years ago

@back2root Your problem is actually very different, it looks like a recursive loop (eventually PHP gives up at 100 levels). Please open a new issue report, using the issue template. Thanks!

davidjericho commented 9 years ago

We've upgraded from OC7 to OC8.1 recently, and we experience exactly this problem. With sharing disabled, the service is snappy and extremely quick. With it turned on, I've noticed we're getting deadlocks on accessing the appconfig table, specifically related to files_sharing.

appconfig is full of records similar to:

MariaDB [owncloudstable81]> select * from appconfig where appid='files_sharing' and configkey > 0 limit 2;
+---------------+-----------+-----------------+
| appid         | configkey | configvalue     |
+---------------+-----------+-----------------+
| files_sharing | 12526     | 1438053344.1823 |
| files_sharing | 12739     | 1438054256.5294 |
+---------------+-----------+-----------------+
2 rows in set (0.00 sec)

At this instant our system has 380 rows in there, this number goes up and down over time.

If I track timing information on the SQL queries, the update for files_sharing is the problem. Most of the time it has to wait for a lock, and the request ends up being serviced after a second or two (although sometimes as long as 20 seconds). Obviously it it results in terrible performance for lots of files, but it's working quietly enough in the background most users don't notice.

For an illustration of how slow, see the following Firefox inspector network timeline: network_-_httpscloudstor aarnet edu auplusind_2015-07-28_14-43-11

However, occasionally I have the following in the owncloud log, a deadlock and exception on the appconfig table.

{
    "reqId": "AJ07757OAGolEqGrzM\/M",
    "remoteAddr": "10.222.111.222",
    "app": "webdav",
    "message": "Exception: {
    \"Message\":\"An exception occurred while executing 'UPDATE appconfig SET configvalue = ? WHERE appid = ? AND configkey = ?' with params [1438054253.89, \\\"files_sharing\\\", \\\"12739\\\"]:\\n\\nSQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction\",\"Code\":0,\"Trace\":\"#0 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/DBALException.php(116): Doctrine\\\\DBAL\\\\Driver\\\\AbstractMySQLDriver->convertException('An exception oc...', Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOException))\\n#1 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/Connection.php(996): Doctrine\\\\DBAL\\\\DBALException::driverExceptionDuringQuery(Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOMySql\\\\Driver), Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOException), 'UPDATE appconfi...', Array)\\n#2 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/lib\\\/private\\\/db\\\/connection.php(151): Doctrine\\\\DBAL\\\\Connection->executeUpdate('UPDATE appconfi...', Array, Array)\\n#3 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/Connection.php(669): OC\\\\DB\\\\Connection->executeUpdate('UPDATE *PREFIX*...', Array, Array)\\n#4 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/lib\\\/private\\\/appconfig.php(210): Doctrine\\\\DBAL\\\\Connection->update('*PREFIX*appconf...', Array, Array)\\n#5 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/lib\\\/private\\\/allconfig.php(148): OC\\\\AppConfig->setValue('files_sharing', '12739', 1438054253.89)\\n#6 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/apps\\\/files_sharing\\\/lib\\\/propagation\\\/recipientpropagator.php(114): OC\\\\AllConfig->setAppValue('files_sharing', '12739', 1438054253.89)\\n#7 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/apps\\\/files_sharing\\\/lib\\\/propagation\\\/recipientpropagator.php(133): OCA\\\\Files_Sharing\\\\Propagation\\\\RecipientPropagator->markDirty(Array, 1438054253.89)\\n#8 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/apps\\\/files_sharing\\\/lib\\\/propagation\\\/recipientpropagator.php(125): OCA\\\\Files_Sharing\\\\Propagation\\\\RecipientPropagator->propagateById(17348995)\\n#9 [internal function]: OCA\\\\Files_Sharing\\\\Propagation\\\\RecipientPropagator->OCA\\\\Files_Sharing\\\\Propagation\\\\{closure}('\\\/Shared\\\/Bison_p...', Array)\\n#10 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/lib\\\/private\\\/hooks\\\/emittertrait.php(98): call_user_func_array(Object(Closure), Array)\\n#11 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/lib\\\/private\\\/files\\\/cache\\\/changepropagator.php(80): OC\\\\Hooks\\\\BasicEmitter->emit('\\\\\\\\OC\\\\\\\\Files', 'propagate', Array)\\n#12 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/lib\\\/private\\\/files\\\/cache\\\/updater.php(92): OC\\\\Files\\\\Cache\\\\ChangePropagator->propagateChanges(NULL)\\n#13 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/lib\\\/private\\\/connector\\\/sabre\\\/file.php(214): OC\\\\Files\\\\Cache\\\\Updater->propagate('\\\/Shared\\\/Bison_p...')\\n#14 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1087): OC\\\\Connector\\\\Sabre\\\\File->put(Resource id #28)\\n#15 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(501): Sabre\\\\DAV\\\\Server->updateFile('Shared\\\/Bison_pr...', Resource id #28, NULL)\\n#16 [internal function]: Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#17 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#18 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(469): Sabre\\\\Event\\\\EventEmitter->emit('method:PUT', Array)\\n#19 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#20 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/apps\\\/files\\\/appinfo\\\/remote.php(83): Sabre\\\\DAV\\\\Server->exec()\\n#21 \\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/remote.php(132): require_once('\\\/cloudstor\\\/www\\\/...')\\n#22 {main}\",\"File\":\"\\\/cloudstor\\\/www\\\/owncloud-stable8.1\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/Driver\\\/AbstractMySQLDriver.php\",\"Line\":115}",
    "level": 4,
    "time": "July 28, 2015 03:30:54"
}

Tracing the php-fpm processes, they consistently stall and wait on UPDATEing appconfig, and quite routinely will stall when doing a SELECT.

It's worth noting that the performance degraded exponentially as the client count increased linearly.

With the rate of connections we have, contention on the appconfig table is a bad thing given how frequently OC 8.1 accesses it.

I've had to work around the issue in the interim by forcing UPDATEs to the appconfig table to another MariaDB cluster member, and doing SELECT against appconfig on other machines, abusing the way MariaDB and Galera do replicated locking.

davidjericho commented 9 years ago

To append further information to this, I'm able to resolve the performance problem for individual users by removing any shares they have initiated. Being the recipient of shares doesn't seem to cause the issue. The factor of degradation appears to be related to the number of recipients.

If I re-share the folders, the performance degrades again. Remove the shares, performance returns.

As noted, the recipient sees no difference in their performance.

PVince81 commented 8 years ago

Is this still happening in 8.2.2 or 9.0 RC1 ?

enoch85 commented 8 years ago

@all Is this still happening in 9.0.2?

lock[bot] commented 5 years ago

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.