Project

General

Profile

Bug #14562

Host index listing takes a long while

Added by Ohad Levy over 5 years ago. Updated over 4 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
Performance
Target version:
-
Difficulty:
Triaged:
No
Bugzilla link:
Pull request:
Fixed in Releases:
Found in Releases:

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.


Related issues

Related to Foreman - Bug #18481: Host index listing takes a long whileClosed2017-02-13

History

#1 Updated by Ohad Levy over 5 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.

#2 Updated by Marek Hulán over 5 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.

#3 Updated by Ohad Levy over 5 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.

#4 Updated by Marek Hulán over 5 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...

#5 Updated by Anonymous over 5 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

#6 Updated by Ohad Levy over 5 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.

#7 Updated by Anonymous over 5 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

#8 Updated by M. Schwipps almost 5 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.

#9 Updated by Timo Goebel over 4 years ago

  • Related to Bug #18481: Host index listing takes a long while added

#10 Updated by Timo Goebel over 4 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.

#11 Updated by Anonymous over 4 years ago

I also added the index. Now it is much faster (~3 secs).

Also available in: Atom PDF