Project

General

Profile

Bug #21964

accessible_resource makes host form very slow

Added by Timo Goebel almost 2 years ago. Updated 11 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Host creation
Target version:
Difficulty:
Triaged:
No
Bugzilla link:
Fixed in Releases:
Found in Releases:

Description

I have investigated slow rendering of the create host form. Page rendering took over one second. For a form. That's pretty bad.

I narrowed it down to accessible_resource.
When adding the following debug code:

def accessible_resource(obj, resource, order = :name, association: resource)
start = Time.now
[...]
duration = (Time.now - start) * 1000
Rails.logger.info "#{controller_name}##{action_name} -> #{__method__} (#{resource} [#{list.size}]): complete: #{duration} ms" 

Shows the following in a production setup with a fast postgres and no traffic on this application server (8 cores, 32 gb ram):

2017-12-13 19:30:04 0febf00c [app] [I] hosts#new -> accessible_resource (smart_proxy [25]): complete: 53.412486 ms
2017-12-13 19:30:04 0febf00c [app] [I] hosts#new -> accessible_resource (hostgroup [142]): complete: 50.485622 ms
2017-12-13 19:30:04 0febf00c [app] [I] hosts#new -> accessible_resource (compute_resource [12]): complete: 51.366071 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (environment [63]): complete: 24.360932 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (realm [1]): complete: 19.958417999999998 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (smart_proxy [25]): complete: 6.319998 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (smart_proxy [25]): complete: 5.165922 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (domain [10]): complete: 20.913355000000003 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (Subnet::Ipv4 [73]): complete: 55.331271 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (Subnet::Ipv6 [2]): complete: 29.389371 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (domain [10]): complete: 6.37227 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (Subnet::Ipv4 [73]): complete: 8.826916 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (Subnet::Ipv6 [2]): complete: 7.112331999999999 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (architecture [2]): complete: 12.670696 ms
2017-12-13 19:30:05 0febf00c [app] [I] hosts#new -> accessible_resource (model [15]): complete: 15.766551999999999 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (smart_proxy [25]): complete: 54.287351 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (hostgroup [142]): complete: 52.016424 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (compute_resource [12]): complete: 62.069528 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (environment [63]): complete: 24.715348000000002 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (realm [1]): complete: 20.959273 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (smart_proxy [25]): complete: 7.982464 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (smart_proxy [25]): complete: 6.361404 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (domain [10]): complete: 22.146929 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (Subnet::Ipv4 [73]): complete: 52.991576 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (Subnet::Ipv6 [2]): complete: 26.410471 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (domain [10]): complete: 5.997154999999999 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (Subnet::Ipv4 [73]): complete: 8.250084 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (Subnet::Ipv6 [2]): complete: 6.461389 ms
2017-12-13 19:30:14 fbeb8fda [app] [I] hosts#new -> accessible_resource (architecture [2]): complete: 12.776512 ms
2017-12-13 19:30:15 fbeb8fda [app] [I] hosts#new -> accessible_resource (model [15]): complete: 74.358535 ms

It's pretty obvious that we have to optimize this. 75ms to get 15 records from the db is not very good.

The smoking gun looks like this:
accessible_resource_records(resource, order).to_a

It's much faster if we call:
accessible_resource_records(resource, order).pluck(:name, id)

This might actually be enough for a lot of select fields.

Associated revisions

Revision 6c1f9563 (diff)
Added by Sebastian Ziebell 11 months ago

Fixes #21964 - extract calculation of new_vm to local variable

  • prepare to pass the value if a vm is newly created
    or not to the template
  • use variable `@vm` when present, avoids fetching host twice
  • re-use status of `new_vm`, set once
  • avoid calling `Host#compute_object` when possible parameter.

History

#1 Updated by The Foreman Bot almost 2 years ago

  • Assignee set to Timo Goebel
  • Status changed from New to Ready For Testing
  • Pull request https://github.com/theforeman/foreman/pull/5095 added

#2 Updated by The Foreman Bot 11 months ago

  • Pull request https://github.com/theforeman/foreman/pull/6321 added

#3 Updated by Ohad Levy 11 months ago

  • Target version set to 1.21.0
  • Fixed in Releases 1.21.0 added
  • Pull request deleted (https://github.com/theforeman/foreman/pull/5095)

removing WIP PR from this issue, if its still relevant please open a new issue for it.

#4 Updated by Anonymous 11 months ago

  • Status changed from Ready For Testing to Closed

Also available in: Atom PDF