Bug #28957
closed
Foreman 1.24.2 - very slow hostgroup view and edit for non admin user
Description
Hello everybody,
in foreman 1.24.2 opening the page for the hostgroup overview or editing hostgroups for non admin user is very slow. Unfortunately I can’t say if the problem came with the update to version 1.24 or if it already existed before.
My test setup contains about 60 servers, 114 host groups, 5 Environment, 136 puppet classes with total of 2594 smart class parameters (but not all are enabled for overwriting). We’re using Foreman as ENC for the puppetserver.
Test as Admin
In the first test i opend the page for the hostgroup overview as admin user. With debug log activated this results in ~ 115 SQL queries. The performance is quiet well (debug out in the attachment: foreman_hostgroup_view_admin.log). Opening the page for editing a hostgroup took some more time. It results in approximately 1200 sql queries. Much more than expected, but the performance was still ok (but noticeably slower) (debug out in the attachment: foreman_hostgroup_edit_admin.log).
Test as Non Admin
For the second test, i created a local testuser with the default role “Viewer”. Furthermore i assigned a role to the testuser, which gave him the possibility to edit all hostgroups. After that i signed into foreman with this user and open the page for the hostgroup overview. This request now took much longer and results in ~ 5000 SQL queries :face_with_monocle: …to show 50 hostgroups, thats quite a lot (debug out in the attachment: foreman_hostgroup_view_testuser.log).
Opening the page for editing a hostgroup took much longer to open. It results in ~ 11000 SQL queries :astonished: (debug out in the attachment: foreman_hostgroup_edit_testuser.log).
best regards
Files
Updated by Christian Fuchs about 4 years ago
Updated by Christian Fuchs about 4 years ago
tbrisker (source https://community.theforeman.org/t/foreman-1-24-2-very-slow-hostgroup-view-and-edit-for-non-admin-user/17222/2)
Thank you for bringing this up!
The reason there are many more sql queries for non-admin user is that we need to do check for authorization for all resources for the user - on the index page, for calculating the host counts, and on the edit page, for all of the different attributes on the form.
Looking at the logs, the SQL queries may be very many, but nearly all of them conclude in <1ms, meaning that the issue is not in inefficient queries but rather in the shear number of them - 11k queries would mean around 10 seconds for the page to load - is this consistent with what you are seeing?
We did have some improvements in the authorization speed that will land in 2.0 but i can’t tell for sure if it will fix this issue for you.
You can also try adding config.active_record.verbose_query_logs = Foreman::Logging.logger('sql') to /usr/share/foreman/config/production.rb which should also add source lines for each sql query so we can see where it is triggered from.
To make sure this thread doesn’t get lost in the history, can you please also open a bug report on our bug tracker?
Updated by Christian Fuchs about 4 years ago
I added "config.active_record.verbose_query_logs = Foreman::Logging.logger('sql') to /usr/share/foreman/config/production.rb" and tried again. The results can be found in the attachment.
Updated by Christian Fuchs about 4 years ago
- File foreman_hostgroup_edit_debug_testuser.log.gz foreman_hostgroup_edit_debug_testuser.log.gz added
- File foreman_hostgroup_view_debug_testuser.log.gz foreman_hostgroup_view_debug_testuser.log.gz added
...adding the missing attachments
Updated by Tomer Brisker about 4 years ago
- Category set to Organizations and Locations
Thanks for the detailed logs and bug report!
Looks like the main hotspot is around https://github.com/theforeman/foreman/blob/1.24.2/app/models/user.rb#L485-L490.
Stats for edit (not sure why, but the line numbers for user.rb seem to be off by a bit):
app/models/user.rb:498 => 939 app/models/user.rb:496 => 632 app/models/concerns/taxonomix.rb:86 => 308 app/models/taxonomy.rb:84 => 308 app/models/concerns/taxonomix.rb:101 => 154 app/helpers/hostgroups_helper.rb:7 => 50 app/models/hostgroup.rb:238 => 50 app/models/concerns/taxonomix.rb:61 => 30 app/models/host/base.rb:53 => 8 app/models/role.rb:123 => 5 app/services/authorizer.rb:48 => 4 app/models/host/base.rb:54 => 3 app/models/user.rb:407 => 3 app/models/user.rb:185 => 3 app/models/user.rb:181 => 3 app/controllers/concerns/foreman/controller/authentication.rb:10 => 3 app/services/authorizer_cache.rb:12 => 2 app/controllers/concerns/application_shared.rb:56 => 2 app/helpers/layout_helper.rb:18 => 1 app/helpers/layout_helper.rb:24 => 1 app/helpers/layout_helper.rb:50 => 1 app/services/authorizer.rb:18 => 1 app/helpers/pagination_helper.rb:3 => 1 app/services/host_counter.rb:39 => 1 app/views/hostgroups/index.html.erb:15 => 1 app/controllers/application_controller.rb:31 => 1
stats for edit:
app/models/user.rb:498 => 4005 app/models/user.rb:496 => 2680 app/models/taxonomy.rb:84 => 1316 app/models/concerns/taxonomix.rb:86 => 1308 app/models/concerns/taxonomix.rb:101 => 658 app/models/hostgroup.rb:152 => 232 app/models/hostgroup.rb:151 => 232 app/models/concerns/nested_ancestry_common.rb:65 => 136 app/models/concerns/nested_ancestry_common.rb:77 => 136 app/models/host/base.rb:53 => 96 app/models/concerns/taxonomix.rb:61 => 92 app/services/authorizer.rb:48 => 62 app/helpers/lookup_keys_helper.rb:47 => 48 app/helpers/application_helper.rb:350 => 48 app/models/host/base.rb:54 => 36 app/models/concerns/host_common.rb:180 => 28 app/models/hostgroup.rb:138 => 22 app/models/hostgroup.rb:137 => 22 app/models/hostgroup.rb:135 => 22 app/models/concerns/host_common.rb:184 => 20 app/models/hostgroup.rb:284 => 12 app/models/concerns/host_common.rb:193 => 12 app/helpers/form_helper.rb:108 => 10 app/models/concerns/host_common.rb:197 => 10 app/helpers/application_helper.rb:461 => 10 app/models/role.rb:123 => 9 app/models/hostgroup.rb:146 => 8 app/models/hostgroup.rb:145 => 8 app/models/concerns/taxonomix.rb:114 => 8 app/views/config_groups/_config_groups_selection.html.erb:28 => 6 app/models/user.rb:407 => 5 app/models/user.rb:185 => 5 app/models/user.rb:181 => 5 app/controllers/concerns/foreman/controller/authentication.rb:10 => 5 app/helpers/form_helper.rb:88 => 4 app/services/association_authorizer.rb:19 => 4 app/models/concerns/taxonomix.rb:232 => 4 app/models/hostgroup.rb:165 => 4 app/models/concerns/host_common.rb:238 => 4 app/models/concerns/nested_ancestry_common.rb:25 => 4 app/helpers/shared_smart_proxies_helper.rb:37 => 4 app/models/concerns/taxonomix.rb:87 => 4 app/controllers/concerns/application_shared.rb:56 => 4 app/helpers/layout_helper.rb:18 => 2 app/helpers/layout_helper.rb:24 => 2 app/helpers/layout_helper.rb:50 => 2 app/models/concerns/taxonomix.rb:179 => 2 app/models/concerns/taxonomix.rb:175 => 2 app/helpers/common_parameters_helper.rb:80 => 2 app/helpers/common_parameters_helper.rb:79 => 2 app/services/authorizer.rb:88 => 2 app/services/authorizer.rb:86 => 2 app/models/hostgroup.rb:168 => 2 app/views/hostgroups/_form.html.erb:85 => 2 app/models/lookup_keys/lookup_key.rb:128 => 2 app/views/puppetclasses/_classes_parameters.html.erb:12 => 2 app/helpers/puppet_related_helper.rb:67 => 2 app/helpers/puppet_related_helper.rb:66 => 2 app/helpers/puppet_related_helper.rb:65 => 2 app/views/common/os_selection/_operatingsystem.html.erb:10 => 2 app/views/common/os_selection/_operatingsystem.html.erb:6 => 2 app/views/common/os_selection/_architecture.html.erb:9 => 2 app/views/hostgroups/_form.html.erb:62 => 2 app/views/hostgroups/_form.html.erb:61 => 2 app/helpers/hosts_helper.rb:332 => 2 app/views/hostgroups/_form.html.erb:55 => 2 app/views/hostgroups/_form.html.erb:54 => 2 app/views/puppetclasses/_class_selection.html.erb:65 => 2 app/views/puppetclasses/_class_selection.html.erb:43 => 2 app/views/puppetclasses/_class_selection.html.erb:42 => 2 app/views/puppetclasses/_class_selection.html.erb:29 => 2 app/views/puppetclasses/_class_selection.html.erb:23 => 2 app/views/config_groups/_config_group.html.erb:24 => 2 app/views/config_groups/_config_group.html.erb:6 => 2 app/views/config_groups/_config_groups_selection.html.erb:9 => 2 app/views/puppetclasses/_class_selection.html.erb:6 => 2 app/helpers/hosts_and_hostgroups_helper.rb:21 => 2 app/helpers/hostgroups_helper.rb:19 => 2 app/helpers/hostgroups_helper.rb:15 => 2 app/helpers/application_helper.rb:356 => 2 app/models/concerns/parameterizable.rb:15 => 2 app/controllers/concerns/find_common.rb:12 => 2
Some statistics about your environment could be useful - how many organizations and locations do you have assigned to the user? are there any nested ones?
We'll continue investigating.
Updated by Christian Fuchs about 4 years ago
Currently we have configured one location and one (main-)organization with 20 nested organizations. All users are assigened to our (main-)organization.
We only use these nested organizations to give write/edit acces for some group of users to the hostgroup. Perhaps there is another way to realize write/edit acces to hostgroups?
Updated by Tomer Brisker about 4 years ago
There can be different ways of defining permissions per hostgroup - you can add a filter to the various permissions, e.g. "hostgroup = development" for hosts or "name = development" for hostgroup permissions.
Updated by Christian Fuchs about 4 years ago
Okay, thanks for the information. Unfortunately this permission concept does not help us.
I also tested on our foreman developement environment with only one organization, the behavior was similar. The reason is probably the high number (600+) of nested hostgroups (in total).
Is there any news about the slow hostgroup yet?
Updated by The Foreman Bot about 4 years ago
- Status changed from New to Ready For Testing
- Assignee set to Shira Maximov
- Pull request https://github.com/theforeman/foreman/pull/7451 added
Updated by Shira Maximov about 4 years ago
- Status changed from Ready For Testing to Closed
Applied in changeset 5b1244d8f11adb4efeb2039a5a6cce756560d445.