Bug #14562
open
Host index listing takes a long while
Description
I've noticed in my production server, that listing hosts takes a while, I've started investiagting, first, the logs:
2016-04-10T12:47:08 [app] [I] Completed 200 OK in 4034ms (Views: 878.4ms | ActiveRecord: 2776.9ms)
Seeing active record takes nearly 3 seconds, made me wonder, so enabling SQL debugging showed one sql query in particular:
2016-04-10T12:47:15 [sql] [D] (2645.7ms) SELECT MAX(`reports`.`id`) AS maximum_id, host_id AS host_id FROM `reports` WHERE `reports`.`type` IN ('ConfigReport') AND `reports`.`host_id` IN (2035, 394, 1951, 1991, 194, 182, 2005, 84666, 84668, 1960, 179, 84680, 1993, 84686, 84672, 84681, 541) GROUP BY `reports`.`host_id`
which made we wonder, why do we need the to query the reports table at all? there are two report related info in the list:
1. link to report (under the last report column), however it always generate the hosts/host/config_reports/last) so in this case its not required.
2. the host config status - but afaik this was stored in a separate table and also we used to keep a bit based value in order to not query the large report table.
I would suggest we avoid doing any queries on the report table while listing the hosts, if we must, it should be async based not to block the entire page to render.
Updated by Ohad Levy almost 9 years ago
for the record, API request on /api/v2/hosts takes 1362 ms. far too much by it self, but probably another ticket for another time.
Updated by Marek Hulán almost 9 years ago
I think the reason was that we have to calculate fresh value of configuration status, otherwise OK -> out-of-sync transition would have to e triggered by some external process.
Updated by Ohad Levy almost 9 years ago
Marek Hulán wrote:
I think the reason was that we have to calculate fresh value of configuration status, otherwise OK -> out-of-sync transition would have to e triggered by some external process.
out of sync is purely a time based calculation, afair host used to have a last reported column? so you would not need to pull that info from the reports table.
even if there are valid reasons, this bug imho is still valid, as it takes more than 50% of the time just to fetch the report info, it might as well be done async.
Updated by Marek Hulán almost 9 years ago
- Category set to Performance
Yeah, I agree it's a valid bug, I just shared why I think it was accessing reports table. Definitely it must be investigated...
Updated by Anonymous almost 9 years ago
I confirm this "bug".
I have about 200 hosts and /hosts query completes in ~3 mins.
2016-04-18T09:45:15 [app] [I] Started GET "/hosts" for x.x.x.x at 2016-04-18 09:45:15 +0200 Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/railties-4.1.14.2/lib/rails/rack/logger.rb:37 method: call_app 2016-04-18T09:45:15 [app] [I] Processing by HostsController#index as HTML Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Rendered hosts/_list.html.erb (1475.9ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Rendered hosts/index.html.erb within layouts/application (1492.9ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Rendered common/_searchbar.html.erb (12.7ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Rendered layouts/_application_content.html.erb (14.5ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Rendered home/_user_dropdown.html.erb (4.2ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Read fragment views/tabs_and_title_records-8 (0.1ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Rendered home/_topbar.html.erb (6.7ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Rendered layouts/base.html.erb (9.4ms) Log trace: /usr/share/foreman/vendor/ruby/2.1.0/gems/activesupport-4.1.14.2/lib/active_support/log_subscriber.rb:93 method: info 2016-04-18T09:48:19 [app] [I] Completed 200 OK in 183947ms (Views: 1513.2ms | ActiveRecord: 182279.8ms)
Debian 8.4
foreman 1.11.0-1
Updated by Ohad Levy almost 9 years ago
Pavel Maryanov wrote:
I confirm this "bug".
I have about 200 hosts and /hosts query completes in ~3 mins.
[...]
Debian 8.4
foreman 1.11.0-1
which DB do you use? I've noticed a huge improvement when I changed from mysql 5.1 to mariadb10.
Updated by Anonymous almost 9 years ago
Ohad Levy wrote:
which DB do you use? I've noticed a huge improvement when I changed from mysql 5.1 to mariadb10.
mysql 5.6.29-76.2
Updated by M. Schwipps about 8 years ago
Here it took for the first call more then 30 seconds and much kernel-IO-wait for about 500 hosts and 2.5m reports.
We upgraded from postgres 9.3 to 9.6 and added the following index to the database
create index index_reports_on_host_id_type_id on reports (host_id, type, id);
Now it's ok.
Updated by Timo Goebel almost 8 years ago
- Related to Bug #18481: Host index listing takes a long while added
Updated by Timo Goebel almost 8 years ago
M. Schwipps wrote:
Here it took for the first call more then 30 seconds and much kernel-IO-wait for about 500 hosts and 2.5m reports.
We upgraded from postgres 9.3 to 9.6 and added the following index to the database
create index index_reports_on_host_id_type_id on reports (host_id, type, id);Now it's ok.
I can confirm, that the index helps a lot. Added #18481 to add a db migration for this.
Updated by Anonymous almost 8 years ago
I also added the index. Now it is much faster (~3 secs).