New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

High load since 9.1.0 #25603

Closed
fladi opened this Issue Jul 25, 2016 · 10 comments

Comments

Projects
None yet
5 participants
@fladi

fladi commented Jul 25, 2016

Our Webserver hosting an OwnCloud instance for ~4500 users went crashing down with loads >150 with 8 CPUs and 16GiB RAM following the 9.1.0 upgrade. Digging into it showed that all PHP processes where busy processing appinfo/info.xml files for all enabled apps.

Is this expected behavior to read those files for each incoming request? For now we vertically upscaled our server by throwing more CPU Cores at it (32 at the moment) to mitigate this.

Steps to reproduce

  1. Open any page
  2. Use strace -p <pid> to see this scrolling by for every single request:
stat("/var/www/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
stat("/var/www/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
stat("/var/www/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
stat("/var/www/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
open("/var/www/owncloud/apps/files/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=613, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 613
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1566, ...}) = 0
stat("/var/www/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1566, ...}) = 0
stat("/var/www/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1566, ...}) = 0
stat("/var/www/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1566, ...}) = 0
open("/var/www/owncloud/apps/activity/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1566, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1566
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
access("/var/www/owncloud/apps/bookmarks", F_OK) = -1 ENOENT (No such file or directory)
stat("/var/www/owncloud/apps/calendar/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=725, ...}) = 0
stat("/var/www/owncloud/apps/calendar/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=725, ...}) = 0
stat("/var/www/owncloud/apps/calendar/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=725, ...}) = 0
stat("/var/www/owncloud/apps/calendar/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=725, ...}) = 0
open("/var/www/owncloud/apps/calendar/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=725, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 725
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=383, ...}) = 0
stat("/var/www/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=383, ...}) = 0
stat("/var/www/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=383, ...}) = 0
stat("/var/www/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=383, ...}) = 0
open("/var/www/owncloud/apps/comments/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=383, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 383
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/contacts/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=487, ...}) = 0
stat("/var/www/owncloud/apps/contacts/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=487, ...}) = 0
stat("/var/www/owncloud/apps/contacts/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=487, ...}) = 0
stat("/var/www/owncloud/apps/contacts/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=487, ...}) = 0
open("/var/www/owncloud/apps/contacts/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=487, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n   "..., 8192) = 487
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=730, ...}) = 0
stat("/var/www/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=730, ...}) = 0
stat("/var/www/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=730, ...}) = 0
stat("/var/www/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=730, ...}) = 0
open("/var/www/owncloud/apps/dav/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=730, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 730
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
access("/var/www/owncloud/apps/documents", F_OK) = -1 ENOENT (No such file or directory)
stat("/var/www/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=481, ...}) = 0
stat("/var/www/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=481, ...}) = 0
stat("/var/www/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=481, ...}) = 0
stat("/var/www/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=481, ...}) = 0
open("/var/www/owncloud/apps/federatedfilesharing/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=481, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n   "..., 8192) = 481
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/federation/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=666, ...}) = 0
stat("/var/www/owncloud/apps/federation/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=666, ...}) = 0
stat("/var/www/owncloud/apps/federation/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=666, ...}) = 0
stat("/var/www/owncloud/apps/federation/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=666, ...}) = 0
open("/var/www/owncloud/apps/federation/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=666, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 666
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_antivirus/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1177, ...}) = 0
stat("/var/www/owncloud/apps/files_antivirus/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1177, ...}) = 0
stat("/var/www/owncloud/apps/files_antivirus/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1177, ...}) = 0
stat("/var/www/owncloud/apps/files_antivirus/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1177, ...}) = 0
open("/var/www/owncloud/apps/files_antivirus/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1177, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1177
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_external/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1663, ...}) = 0
stat("/var/www/owncloud/apps/files_external/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1663, ...}) = 0
stat("/var/www/owncloud/apps/files_external/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1663, ...}) = 0
stat("/var/www/owncloud/apps/files_external/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1663, ...}) = 0
open("/var/www/owncloud/apps/files_external/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1663, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1663
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_pdfviewer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1062, ...}) = 0
stat("/var/www/owncloud/apps/files_pdfviewer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1062, ...}) = 0
stat("/var/www/owncloud/apps/files_pdfviewer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1062, ...}) = 0
stat("/var/www/owncloud/apps/files_pdfviewer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1062, ...}) = 0
open("/var/www/owncloud/apps/files_pdfviewer/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1062, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n   "..., 8192) = 1062
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_sharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1312, ...}) = 0
stat("/var/www/owncloud/apps/files_sharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1312, ...}) = 0
stat("/var/www/owncloud/apps/files_sharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1312, ...}) = 0
stat("/var/www/owncloud/apps/files_sharing/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1312, ...}) = 0
open("/var/www/owncloud/apps/files_sharing/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1312, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1312
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_texteditor/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=936, ...}) = 0
stat("/var/www/owncloud/apps/files_texteditor/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=936, ...}) = 0
stat("/var/www/owncloud/apps/files_texteditor/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=936, ...}) = 0
stat("/var/www/owncloud/apps/files_texteditor/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=936, ...}) = 0
open("/var/www/owncloud/apps/files_texteditor/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=936, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 936
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_trashbin/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1422, ...}) = 0
stat("/var/www/owncloud/apps/files_trashbin/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1422, ...}) = 0
stat("/var/www/owncloud/apps/files_trashbin/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1422, ...}) = 0
stat("/var/www/owncloud/apps/files_trashbin/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1422, ...}) = 0
open("/var/www/owncloud/apps/files_trashbin/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1422, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1422
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_versions/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1360, ...}) = 0
stat("/var/www/owncloud/apps/files_versions/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1360, ...}) = 0
stat("/var/www/owncloud/apps/files_versions/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1360, ...}) = 0
stat("/var/www/owncloud/apps/files_versions/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1360, ...}) = 0
open("/var/www/owncloud/apps/files_versions/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1360, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1360
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/files_videoplayer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=548, ...}) = 0
stat("/var/www/owncloud/apps/files_videoplayer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=548, ...}) = 0
stat("/var/www/owncloud/apps/files_videoplayer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=548, ...}) = 0
stat("/var/www/owncloud/apps/files_videoplayer/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=548, ...}) = 0
open("/var/www/owncloud/apps/files_videoplayer/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=548, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 548
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/gallery/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1140, ...}) = 0
stat("/var/www/owncloud/apps/gallery/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1140, ...}) = 0
stat("/var/www/owncloud/apps/gallery/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1140, ...}) = 0
stat("/var/www/owncloud/apps/gallery/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1140, ...}) = 0
open("/var/www/owncloud/apps/gallery/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1140, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1140
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
access("/var/www/owncloud/apps/html5_videoplayer", F_OK) = -1 ENOENT (No such file or directory)
stat("/var/www/owncloud/apps/notes/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=607, ...}) = 0
stat("/var/www/owncloud/apps/notes/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=607, ...}) = 0
stat("/var/www/owncloud/apps/notes/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=607, ...}) = 0
stat("/var/www/owncloud/apps/notes/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=607, ...}) = 0
open("/var/www/owncloud/apps/notes/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=607, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n   "..., 8192) = 607
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/notifications/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=617, ...}) = 0
stat("/var/www/owncloud/apps/notifications/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=617, ...}) = 0
stat("/var/www/owncloud/apps/notifications/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=617, ...}) = 0
stat("/var/www/owncloud/apps/notifications/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=617, ...}) = 0
open("/var/www/owncloud/apps/notifications/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=617, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 617
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1171, ...}) = 0
stat("/var/www/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1171, ...}) = 0
stat("/var/www/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1171, ...}) = 0
stat("/var/www/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1171, ...}) = 0
open("/var/www/owncloud/apps/provisioning_api/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1171, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?> \n<info>\n\t<"..., 8192) = 1171
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=573, ...}) = 0
stat("/var/www/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=573, ...}) = 0
stat("/var/www/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=573, ...}) = 0
stat("/var/www/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=573, ...}) = 0
open("/var/www/owncloud/apps/systemtags/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=573, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 573
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/tasks/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=401, ...}) = 0
stat("/var/www/owncloud/apps/tasks/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=401, ...}) = 0
stat("/var/www/owncloud/apps/tasks/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=401, ...}) = 0
stat("/var/www/owncloud/apps/tasks/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=401, ...}) = 0
open("/var/www/owncloud/apps/tasks/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=401, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 401
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=541, ...}) = 0
stat("/var/www/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=541, ...}) = 0
stat("/var/www/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=541, ...}) = 0
stat("/var/www/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=541, ...}) = 0
open("/var/www/owncloud/apps/updatenotification/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=541, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 541
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)                               = 0
stat("/var/www/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1442, ...}) = 0
stat("/var/www/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1442, ...}) = 0
stat("/var/www/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1442, ...}) = 0
stat("/var/www/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0644, st_size=1442, ...}) = 0
open("/var/www/owncloud/apps/user_ldap/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0644, st_size=1442, ...}) = 0
lseek(11, 0, SEEK_CUR)                  = 0
read(11, "<?xml version=\"1.0\"?>\n<info>\n\t<i"..., 8192) = 1442
read(11, "", 8192)                      = 0
read(11, "", 8192)                      = 0
close(11)

Server configuration

Operating system:
Debian 8 amd64

Web server:
Tried two setups, both exhibit the same behavior.

  • Apache 2.4 with mod_php7
  • Nginx 1.9.10 with FPM

Database:
MariaDB 10

PHP version:
7.0.9

ownCloud version: (see ownCloud admin page)
9.1.0

Updated from an older ownCloud or fresh install:
Updated from OC 8.2

Where did you install ownCloud from:
http://download.owncloud.org/download/repositories/stable/Debian_8.0/

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.

List of activated apps:
Enabled:

  • activity: 2.3.2
  • calendar: true
  • comments: 0.3.0
  • contacts: true
  • dav: 0.2.5
  • federatedfilesharing: 0.3.0
  • federation: 0.1.0
  • files: 1.5.1
  • files_antivirus: true
  • files_external: 0.6.0
  • files_pdfviewer: 0.8.1
  • files_sharing: 0.10.0
  • files_texteditor: 2.1
  • files_trashbin: 0.9.0
  • files_versions: 1.3.0
  • files_videoplayer: 0.9.8
  • gallery: 15.0.0
  • notes: 2.0.1
  • notifications: 0.3.0
  • provisioning_api: 0.5.0
  • systemtags: 0.3.0
  • tasks: true
  • updatenotification: 0.2.1
  • user_ldap: 0.9.0
If you have access to your command line run e.g.:
sudo -u www-data php occ app:list
from within your ownCloud installation folder

The content of config/config.php:

{
    "system": {
        "instanceid": "oc7eea03d4fa",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "box.example.com"
        ],
        "datadirectory": "\/var\/lib\/owncloud\/data",
        "version": "9.1.0.15",
        "dbtype": "mysql",
        "dbhost": "localhost",
        "dbname": "box.example.com",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "dbtableprefix": "oc_",
        "installed": true,
        "default_language": "de",
        "defaultapp": "files",
        "knowledgebaseenabled": true,
        "enable_avatars": true,
        "allow_user_to_change_display_name": false,
        "remember_login_cookie_lifetime": 1296000,
        "session_lifetime": 86400,
        "session_keepalive": true,
        "mail_domain": "example.com",
        "mail_from_address": "owncloud",
        "mail_smtpdebug": false,
        "mail_smtpmode": "sendmail",
        "mail_smtphost": "localhost",
        "mail_smtpport": 25,
        "mail_smtptimeout": 10,
        "mail_smtpauth": false,
        "overwritehost": "box.example.com",
        "overwriteprotocol": "https",
        "overwritewebroot": "\/",
        "updatechecker": false,
        "has_internet_connection": true,
        "check_for_working_webdav": true,
        "check_for_working_htaccess": false,
        "config_is_read_only": false,
        "integrity.check.disabled": true,
        "log_type": "owncloud",
        "logfile": "\/var\/log\/owncloud\/owncloud.log",
        "loglevel": 3,
        "logdateformat": "F d, Y H:i:s",
        "logtimezone": "Europe\/Vienna",
        "cron_log": true,
        "cron.lockfile.location": "\/tmp",
        "appstoreenabled": true,
        "apps_paths": [
            {
                "path": "\/var\/www\/owncloud\/apps",
                "url": "\/apps",
                "writable": true
            }
        ],
        "enable_previews": true,
        "preview_libreoffice_path": "\/usr\/bin\/libreoffice",
        "preview_office_cl_parameters": " --headless --nologo --nofirststartwizard --invisible --norestore -convert-to pdf -outdir ",
        "ldapUserCleanupInterval": 51,
        "maintenance": false,
        "singleuser": false,
        "memcache.local": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "\/run\/redis\/redis.sock",
            "port": 0,
            "timeout": 0,
            "dbindex": 1
        },
        "tempdirectory": "\/tmp",
        "blacklisted_files": [
            ".htaccess"
        ],
        "theme": "mug",
        "quota_include_external_storage": false,
        "asset-pipeline.enabled": true,
        "mount_file": "\/var\/www\/owncloud\/data\/mount.json",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "max_filesize_animated_gifs_public_sharing": 10,
        "filelocking.enabled": true,
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "activity_expire_days": 600
    },
    "apps": {
        "252FB540-4F16-01DB-800D-001438EF": {
            "documents": "save_path"
        },
        "7C73779C-769A-4E9C-C882-9C77737C": {
            "documents": "save_path"
        },
        "87303A78-E8EF-4CFB-AD99-783A3087": {
            "documents": "save_path"
        },
        "8A94DA79-BBDF-48BB-A1A0-79DA948A": {
            "documents": "save_path"
        },
        "9BBB6E50-4F0E-01DB-800D-001438EF": {
            "documents": "save_path"
        },
        "DC3F8FD0-57C1-01DC-8098-001438EF": {
            "documents": "save_path"
        },
        "activity": {
            "enabled": "yes",
            "installed_version": "2.3.2",
            "types": "filesystem"
        },
        "audios": {
            "enabled": "no",
            "installed_version": "1.2.5",
            "ocsid": "170562",
            "types": ""
        },
        "backgroundjob": {
            "lastjob": "83924"
        },
        "bookmarks": {
            "enabled": "yes",
            "installed_version": "0.7",
            "ocsid": "168710",
            "types": ""
        },
        "calendar": {
            "enabled": "yes",
            "installed_version": "0",
            "ocsid": "168707",
            "signed": "true",
            "types": ""
        },
        "comments": {
            "enabled": "yes",
            "installed_version": "0.3.0",
            "types": "logging"
        },
        "contacts": {
            "backend_ldap": "true",
            "enabled": "yes",
            "installed_version": "0",
            "ocsid": "168708",
            "types": ""
        },
        "core": {
            "backgroundjobs_mode": "cron",
            "global_cache_gc_lastrun": "1448267401",
            "installedat": "1411393558.632",
            "lastcron": "1469450712",
            "lastupdateResult": "[]",
            "lastupdatedat": "1469374201",
            "oc.integritycheck.checker": "[]",
            "public_caldav": "calendar\/share.php",
            "public_calendar": "calendar\/share.php",
            "public_documents": "documents\/public.php",
            "public_files": "files_sharing\/public.php",
            "public_gallery": "gallery\/public.php",
            "public_webdav": "dav\/appinfo\/v1\/publicwebdav.php",
            "remote_caldav": "dav\/appinfo\/v1\/caldav.php",
            "remote_calendar": "dav\/appinfo\/v1\/caldav.php",
            "remote_carddav": "dav\/appinfo\/v1\/carddav.php",
            "remote_contacts": "dav\/appinfo\/v1\/carddav.php",
            "remote_dav": "dav\/appinfo\/v2\/remote.php",
            "remote_files": "dav\/appinfo\/v1\/webdav.php",
            "remote_filesync": "files\/appinfo\/filesync.php",
            "remote_mozilla_sync": "mozilla_sync\/appinfo\/remote.php",
            "remote_webdav": "dav\/appinfo\/v1\/webdav.php",
            "repairlegacystoragesdone": "yes",
            "shareapi_allow_mail_notification": "yes",
            "shareapi_allow_public_notification": "yes",
            "shareapi_default_expire_date": "yes",
            "umgmt_send_email": "false",
            "umgmt_show_backend": "false",
            "umgmt_show_email": "false",
            "umgmt_show_last_login": "false",
            "umgmt_show_storage_location": "false"
        },
        "dav": {
            "enabled": "yes",
            "installed_version": "0.2.5",
            "types": "filesystem"
        },
        "documents": {
            "converter": "local",
            "enabled": "yes",
            "installed_version": "0.12.0",
            "ocsid": "168711",
            "types": "",
            "unstable": "false"
        },
        "external": {
            "enabled": "no",
            "installed_version": "1.1",
            "ocsid": "166046",
            "types": ""
        },
        "federatedfilesharing": {
            "enabled": "yes",
            "installed_version": "0.3.0",
            "types": ""
        },
        "federation": {
            "enabled": "yes",
            "installed_version": "0.1.0",
            "types": "authentication"
        },
        "files": {
            "cronjob_scan_files": "4000",
            "default_quota": "none",
            "enabled": "yes",
            "installed_version": "1.5.1",
            "types": "filesystem"
        },
        "files_antivirus": {
            "av_chunk_size": "10485760",
            "av_cmd_options": "",
            "av_host": "",
            "av_infected_action": "delete",
            "av_mode": "socket",
            "av_path": "\/usr\/bin\/clamscan",
            "av_port": "0",
            "av_socket": "\/var\/run\/clamav\/clamd.ctl",
            "enabled": "yes",
            "infected_action": "delete",
            "installed_version": "0",
            "ocsid": "157439",
            "signed": "true",
            "types": "filesystem"
        },
        "files_encryption": {
            "enabled": "no",
            "installed_version": "0.6.1",
            "ocsid": "166047",
            "publicShareKeyId": "pubShare_ec8f08b6",
            "recoveryAdminEnabled": "1",
            "recoveryKeyId": "recovery_5f2f25d1",
            "types": "filesystem"
        },
        "files_external": {
            "enabled": "yes",
            "google::1015957022984-ii3n47g3tf1ufpuc1467112086cId": "6322",
            "google::144360292977-e67p6qfin1m38v68o1464768868cId": "14078",
            "google::258497229349-7ls7ai9l7tmnl2ebq1464790306cId": "3653",
            "google::836576060527-s49fgrbbbn5bgojet1467244829cId": "148",
            "installed_version": "0.6.0",
            "ocsid": "166048",
            "types": "filesystem",
            "user_mounting_backends": "owncloud,dropbox,googledrive,swift"
        },
        "files_pdfviewer": {
            "enabled": "yes",
            "installed_version": "0.8.1",
            "ocsid": "166049",
            "types": ""
        },
        "files_sharing": {
            "enabled": "yes",
            "installed_version": "0.10.0",
            "types": "filesystem"
        },
        "files_texteditor": {
            "enabled": "yes",
            "installed_version": "2.1",
            "ocsid": "166051",
            "types": ""
        },
        "files_trashbin": {
            "enabled": "yes",
            "installed_version": "0.9.0",
            "types": "filesystem"
        },
        "files_versions": {
            "enabled": "yes",
            "installed_version": "1.3.0",
            "types": "filesystem"
        },
        "files_videoplayer": {
            "enabled": "yes",
            "installed_version": "0.9.8",
            "types": ""
        },
        "files_videoviewer": {
            "enabled": "no",
            "installed_version": "0.1.3",
            "ocsid": "166054",
            "types": ""
        },
        "firstrunwizard": {
            "enabled": "no",
            "installed_version": "1.1",
            "ocsid": "166055",
            "types": ""
        },
        "gallery": {
            "enabled": "yes",
            "installed_version": "15.0.0",
            "types": ""
        },
        "grauphel": {
            "enabled": "no",
            "installed_version": "0.6.1",
            "types": ""
        },
        "html5_videoplayer": {
            "enabled": "yes",
            "installed_version": "1.0",
            "ocsid": "173950",
            "types": ""
        },
        "mozilla_sync": {
            "enabled": "no",
            "installed_version": "1.4",
            "types": ""
        },
        "music": {
            "enabled": "no",
            "installed_version": "0.3.11",
            "ocsid": "164319",
            "types": "filesystem"
        },
        "news": {
            "enabled": "no",
            "installed_version": "8.8.0",
            "ocsid": "168040",
            "types": ""
        },
        "notes": {
            "enabled": "yes",
            "installed_version": "2.0.1",
            "ocsid": "174554",
            "types": ""
        },
        "notifications": {
            "enabled": "yes",
            "installed_version": "0.3.0",
            "types": "logging"
        },
        "provisioning_api": {
            "enabled": "yes",
            "installed_version": "0.5.0",
            "types": "prevent_group_restriction"
        },
        "search_lucene": {
            "enabled": "no",
            "installed_version": "0.5.3",
            "ocsid": "168709",
            "types": "filesystem"
        },
        "systemtags": {
            "enabled": "yes",
            "installed_version": "0.3.0",
            "types": "logging"
        },
        "tasks": {
            "enabled": "yes",
            "installed_version": "0",
            "ocsid": "164356",
            "signed": "true",
            "types": ""
        },
        "tasks_enhanced": {
            "enabled": "no",
            "installed_version": "0.4.1",
            "types": ""
        },
        "templateeditor": {
            "enabled": "no",
            "installed_version": "0.1",
            "types": ""
        },
        "updatenotification": {
            "calendar": "1.3.0",
            "enabled": "yes",
            "installed_version": "0.2.1",
            "types": ""
        },
        "updater": {
            "enabled": "no",
            "installed_version": "0.6",
            "types": ""
        },
        "user_ldap": {
            "cleanUpJobOffset": "4950",
            "enabled": "yes",
            "enforce_home_folder_naming_rule": "",
            "has_memberof_filter_support": "0",
            "home_folder_naming_rule": "",
            "installed_version": "0.9.0",
            "last_jpegPhoto_lookup": "0",
            "ldap_agent_password": "cmVhZDRsZGFw",
            "ldap_attributes_for_group_search": "",
            "ldap_attributes_for_user_search": "",
            "ldap_backup_host": "",
            "ldap_backup_port": "",
            "ldap_base": "ou=usr,o=mug",
            "ldap_base_groups": "ou=grp,o=mug",
            "ldap_base_users": "ou=usr,o=mug",
            "ldap_cache_ttl": "600",
            "ldap_configuration_active": "1",
            "ldap_display_name": "fullname",
            "ldap_dn": "cn=omldapread,ou=syst,ou=usr,o=mug",
            "ldap_dynamic_group_member_url": "",
            "ldap_email_attr": "mail",
            "ldap_experienced_admin": "1",
            "ldap_expert_username_attr": "",
            "ldap_expert_uuid_group_attr": "",
            "ldap_expert_uuid_user_attr": "",
            "ldap_group_display_name": "cn",
            "ldap_group_filter": "(&(objectclass=groupOfNames)(o=*)(DirXML-Associations=*))",
            "ldap_group_filter_mode": "1",
            "ldap_group_member_assoc_attribute": "uniqueMember",
            "ldap_groupfilter_groups": "",
            "ldap_groupfilter_objectclass": "",
            "ldap_host": "ldap.example.com",
            "ldap_login_filter": "(&(objectclass=Person)(|(uid=%uid)(mail=%uid))(|(CO-ACCOUNTTYPE-C=BEDIENSTETE)(CO-ACCOUNTTYPE-C=Maschinen)))",
            "ldap_login_filter_mode": "1",
            "ldap_loginfilter_attributes": "",
            "ldap_loginfilter_email": "0",
            "ldap_loginfilter_username": "1",
            "ldap_nested_groups": "0",
            "ldap_override_main_server": "0",
            "ldap_paging_size": "500",
            "ldap_port": "389",
            "ldap_quota_attr": "",
            "ldap_quota_def": "",
            "ldap_tls": "0",
            "ldap_turn_off_cert_check": "0",
            "ldap_user_display_name_2": "",
            "ldap_user_filter_mode": "1",
            "ldap_userfilter_groups": "",
            "ldap_userfilter_objectclass": "Person",
            "ldap_userlist_filter": "(&(objectclass=Person)(|(CO-ACCOUNTTYPE-C=BEDIENSTETE)(CO-ACCOUNTTYPE-C=Maschinen)))",
            "types": "authentication",
            "use_memberof_to_detect_membership": "1"
        }
    }
}

Are you using external storage, if yes which one: NFS-mounted data directory

Are you using encryption: no (we did use it at first but disabled it later on)

Are you using an external user-backend, if yes which one: LDAP (eDirectory)

@DeepDiver1975 DeepDiver1975 added this to the 9.1.1 milestone Jul 25, 2016

@DeepDiver1975

This comment has been minimized.

Show comment
Hide comment
@DeepDiver1975

DeepDiver1975 Jul 25, 2016

Member

As far as debugging shows this is caused by https://github.com/owncloud/core/blob/master/lib/private/AppFramework/App.php#L59 which is called by registerAutoloading on every request - ee3457a

Member

DeepDiver1975 commented Jul 25, 2016

As far as debugging shows this is caused by https://github.com/owncloud/core/blob/master/lib/private/AppFramework/App.php#L59 which is called by registerAutoloading on every request - ee3457a

@DeepDiver1975

This comment has been minimized.

Show comment
Hide comment
@DeepDiver1975

DeepDiver1975 Jul 25, 2016

Member

We need to look into mechanisms to read such information from a cache.

Instead of parsing the xml over and over again we shall use:

            $info = $this->appManager->getAppInfo($appId);
Member

DeepDiver1975 commented Jul 25, 2016

We need to look into mechanisms to read such information from a cache.

Instead of parsing the xml over and over again we shall use:

            $info = $this->appManager->getAppInfo($appId);

@DeepDiver1975 DeepDiver1975 self-assigned this Jul 25, 2016

@fladi

This comment has been minimized.

Show comment
Hide comment
@fladi

fladi Jul 25, 2016

It seems that parsing info.xml was in fact not the root cause for our load spike but rather a user putting a large image (~60MiB) into an appointment on a shared calendar which MariaDB could not handle. This caused a level 3 error message to be written to the logfile, including the whole image. We had to increase innodb_log_file_size to make the UPDATE query pass. We are not yet certain how this cause this huge load spike but it seems to be resolved by now.

If you want, you can close this issue. Or keep it around to tweak a bit of performance out of App.php.

fladi commented Jul 25, 2016

It seems that parsing info.xml was in fact not the root cause for our load spike but rather a user putting a large image (~60MiB) into an appointment on a shared calendar which MariaDB could not handle. This caused a level 3 error message to be written to the logfile, including the whole image. We had to increase innodb_log_file_size to make the UPDATE query pass. We are not yet certain how this cause this huge load spike but it seems to be resolved by now.

If you want, you can close this issue. Or keep it around to tweak a bit of performance out of App.php.

@starlessboi

This comment has been minimized.

Show comment
Hide comment
@starlessboi

starlessboi Jul 28, 2016

I also see the same weird behavior today...probably after upgrade to 9.1.0
all of CPU is overeaten by php-fpm process

starlessboi commented Jul 28, 2016

I also see the same weird behavior today...probably after upgrade to 9.1.0
all of CPU is overeaten by php-fpm process

@fladi

This comment has been minimized.

Show comment
Hide comment
@fladi

fladi Aug 3, 2016

Sorry, this issue has popped up again. I looked at the code using blackfire and it seems that simplexml_load_file is called 265 times for a single request. We are now back at 24 CPUs at full load and a completely unresponsive server.

fladi commented Aug 3, 2016

Sorry, this issue has popped up again. I looked at the code using blackfire and it seems that simplexml_load_file is called 265 times for a single request. We are now back at 24 CPUs at full load and a completely unresponsive server.

@fladi

This comment has been minimized.

Show comment
Hide comment
@fladi

fladi Aug 4, 2016

So, after a night of profiling with blackfire, I was able to cut the calls to simplexml_load_file down to 48 (from 265) by using memoization for OC\AppFramework\App::buildAppNamespace and OC\App\InfoParser::parse. I would be able to reduce them further so that for each app the info.xml file gets only parsed once if buildAppNamespace would use parse or vice versa.

There are several other IO-heavy candidates that could be optimized by wrapping them in a memoization pattern, e.g. OC\Files\Storage\Local::free_space.

fladi commented Aug 4, 2016

So, after a night of profiling with blackfire, I was able to cut the calls to simplexml_load_file down to 48 (from 265) by using memoization for OC\AppFramework\App::buildAppNamespace and OC\App\InfoParser::parse. I would be able to reduce them further so that for each app the info.xml file gets only parsed once if buildAppNamespace would use parse or vice versa.

There are several other IO-heavy candidates that could be optimized by wrapping them in a memoization pattern, e.g. OC\Files\Storage\Local::free_space.

@PVince81

This comment has been minimized.

Show comment
Hide comment
@PVince81

PVince81 Aug 9, 2016

Member

which is called by registerAutoloading on every request

There were autoloader changes in 9.1, could that be related ?

Member

PVince81 commented Aug 9, 2016

which is called by registerAutoloading on every request

There were autoloader changes in 9.1, could that be related ?

@BobRyanConsulting

This comment has been minimized.

Show comment
Hide comment
@BobRyanConsulting

BobRyanConsulting Aug 15, 2016

Just to throw it out there, we just upgraded from v9.0.2 to v9.1.0 and were met with spinning cursors waiting for login. Looking at the httpd or php processes showed the same behavior of info.xml being opened for each app over and over and over. I gave up after a few minutes and restored the old database.

[root@ioc html]# strace -p 14338
Process 14338 attached
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
open("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, " \n\n\t<"..., 8192) = 1130
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
open("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 536
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
open("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 1050
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
open("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 395
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
open("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 1282
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM oc_file"..., 82) = 82 read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 133 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) write(3, "O\0\0\0\3SELECTpathFROMoc_file"..., 83) = 83
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM oc_file"..., 82) = 82 read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) write(3, "P\0\0\0\3SELECTpathFROMoc_file"..., 84) = 84
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM oc_file"..., 82) = 82 read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) write(3, "N\0\0\0\3SELECTpathFROMoc_file"..., 82) = 82
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM `oc_file"..., 82) = 82
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
open("/var/www/html/owncloud/apps/files/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 415
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
open("/var/www/html/owncloud/apps/activity/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 1053
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
open("/var/www/html/owncloud/apps/comments/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 380
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
open("/var/www/html/owncloud/apps/dav/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 838
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
open("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n "..., 8192) = 487
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0

BobRyanConsulting commented Aug 15, 2016

Just to throw it out there, we just upgraded from v9.0.2 to v9.1.0 and were met with spinning cursors waiting for login. Looking at the httpd or php processes showed the same behavior of info.xml being opened for each app over and over and over. I gave up after a few minutes and restored the old database.

[root@ioc html]# strace -p 14338
Process 14338 attached
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
stat("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
open("/var/www/html/owncloud/apps/provisioning_api/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1130, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, " \n\n\t<"..., 8192) = 1130
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
stat("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
open("/var/www/html/owncloud/apps/systemtags/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=536, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 536
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
stat("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
open("/var/www/html/owncloud/apps/templateeditor/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1050, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 1050
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
stat("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
open("/var/www/html/owncloud/apps/updatenotification/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=395, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 395
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
stat("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
open("/var/www/html/owncloud/apps/user_ldap/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1282, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 1282
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM oc_file"..., 82) = 82 read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 133 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) write(3, "O\0\0\0\3SELECTpathFROMoc_file"..., 83) = 83
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM oc_file"..., 82) = 82 read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) write(3, "P\0\0\0\3SELECTpathFROMoc_file"..., 84) = 84
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM oc_file"..., 82) = 82 read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84 poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout) write(3, "N\0\0\0\3SELECTpathFROMoc_file"..., 82) = 82
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(3, "N\0\0\0\3SELECT path FROM `oc_file"..., 82) = 82
read(3, "\1\0\0\1\0019\0\0\2\3def\3ioc\foc_filecache\fo"..., 16384) = 84
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
stat("/var/www/html/owncloud/apps/files/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
open("/var/www/html/owncloud/apps/files/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=415, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 415
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
stat("/var/www/html/owncloud/apps/activity/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
open("/var/www/html/owncloud/apps/activity/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=1053, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 1053
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
stat("/var/www/html/owncloud/apps/comments/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
open("/var/www/html/owncloud/apps/comments/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=380, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 380
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
stat("/var/www/html/owncloud/apps/dav/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
open("/var/www/html/owncloud/apps/dav/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=838, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n\t<i"..., 8192) = 838
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
stat("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
open("/var/www/html/owncloud/apps/federatedfilesharing/appinfo/info.xml", O_RDONLY) = 11
fstat(11, {st_mode=S_IFREG|0640, st_size=487, ...}) = 0
lseek(11, 0, SEEK_CUR) = 0
read(11, "\n\n "..., 8192) = 487
read(11, "", 8192) = 0
read(11, "", 8192) = 0
close(11) = 0

@PVince81

This comment has been minimized.

Show comment
Hide comment
@PVince81

PVince81 Aug 19, 2016

Member

Please try again with 9.1.1 RC1, there was an issue with recursions and loops in the code.

Member

PVince81 commented Aug 19, 2016

Please try again with 9.1.1 RC1, there was an issue with recursions and loops in the code.

@PVince81

This comment has been minimized.

Show comment
Hide comment
@PVince81

PVince81 Aug 19, 2016

Member

ah, info.xml you say, probably unrelated then...

Member

PVince81 commented Aug 19, 2016

ah, info.xml you say, probably unrelated then...

DeepDiver1975 added a commit that referenced this issue Aug 19, 2016

@PVince81 PVince81 modified the milestones: 9.1.2, 9.1.1 Sep 21, 2016

DeepDiver1975 added a commit that referenced this issue Sep 23, 2016

DeepDiver1975 added a commit that referenced this issue Oct 10, 2016

[stable9.1] Don't parse info.xml but reuse already cached app infos - f…
…ixes #25603 (#25968)

* Don't parse info.xml but reuse already cached app infos - fixes #25603

* Use === in InfoParser. Fixes test

* InfoParser should not depend on UrlGenerator - fixes issue with session being closed too early
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment