Plugins » Foreman Remote Execution

Please bare with me.. my first official bug report. Please let me know of issues!

Original report reference: https://community.theforeman.org/t/loading-job-invocations-extremely-slow-for-non-admin-users/16034

Problem: Listing and listing job invocations on Foreman gui as non-admin takes excessive RAM and user is painfully slow (20-90 seconds).

RAM use on the system goes from 7-8GB to 15GB+ and goes deep into the system's 4GB swap

Observed Endpoints:
/job_invocations
admin: 2-3 sec
non-admin: 4-6 sec

/job_invocations/[id]
admin: 3 sec
non-admin: 25-100 sec < Worst offender by far

template_invocations/[id]
admin: 3-4 sec
non-admin: 9 sec

Expected outcome: non-admin requests should be nearly as performant as a full admin

Foreman and Proxy versions: 1.23.0 and 1.23.1

Foreman Remote Execution version: 1.8.2

Distribution and version: CentOS 7.7.1908

Other relevant data:

CPU usage for passenger process goes to ~100% for the duration of the request (Passenger RackApp: /usr/share/foreman )
only 105 hosts in the Foreman system
16GB RAM and 2 vCPU - low utilization normally

This seems similar to Bug #19742: API call for fact_values is slow when user is non-admin , Foreman 1.15.0 - Foreman, just with Job Invocations instead of facts.

Note: We also had to disable batching due to Bug #28095 , which I suspect may be compounding the issue: Remote Execution job runs the command on all servers simultaneously, even when set to distribute over X seconds

I have debug logging and permissions logging enabled. I couldn’t find anything useful except to note that the rendered requests really did take a very long time.
e.g.

Completed 200 OK in 32792ms (Views: 31735.4ms | ActiveRecord: 961.6ms)
Completed 200 OK in 55735ms (Views: 47333.0ms | ActiveRecord: 7576.2ms)
Completed 200 OK in 42509ms (Views: 37509.6ms | ActiveRecord: 4392.4ms)
Completed 200 OK in 23215ms (Views: 22198.0ms | ActiveRecord: 923.7ms)

The most recent event I dug into had severe timings:

2020-01-10T04:59:17 [I|app|20099029]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (81972.3ms)
2020-01-10T04:59:16 [I|app|d3971957]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (83887.9ms)
2020-01-10T04:59:15 [I|app|69267482]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (84842.5ms)
2020-01-10T04:59:05 [I|app|2aec0912]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (78597.8ms)
2020-01-10T04:57:15 [I|app|3f3de6df]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (94779.2ms)
2020-01-10T04:57:15 [I|app|62be3656]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (92773.5ms)
2020-01-10T04:57:12 [I|app|a5da604d]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (94065.5ms)
2020-01-10T04:57:10 [I|app|c3f699ce]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (92016.9ms)
2020-01-10T04:57:02 [I|app|431f304e]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (89568.3ms)
2020-01-10T04:54:58 [I|app|1c4321b5]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (87785.9ms)
2020-01-10T04:54:58 [I|app|edf85e53]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (93964.0ms)
2020-01-10T04:54:57 [I|app|f026c7ca]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (95719.9ms)
2020-01-10T04:54:57 [I|app|bd03307c]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (91968.9ms)
2020-01-10T04:54:42 [I|app|404bd02d]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (81909.5ms)
2020-01-10T04:51:39 [I|app|30fe9753]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (35361.5ms)
2020-01-10T04:51:35 [I|app|4f739e84]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (33960.5ms)
2020-01-10T04:48:19 [I|app|da0c6a34]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (65648.0ms)
2020-01-10T04:48:16 [I|app|ffe015e5]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (60804.2ms)
2020-01-10T04:48:16 [I|app|ff20e799]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (68352.7ms)
2020-01-10T04:48:01 [I|app|e1ed1819]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (63092.3ms)
2020-01-10T04:47:15 [I|app|b70a360e]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/template_invocations/show.html.erb within layouts/application (35297.0ms)
2020-01-10T04:43:40 [I|app|8dc1b6f8]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/job_invocations/show.html.erb within layouts/application (378909.1ms)
2020-01-10T04:40:40 [I|app|4e340aca]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/job_invocations/show.html.erb within layouts/application (201886.4ms)
2020-01-10T04:36:29 [I|app|9857093b]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/job_invocations/index.html.erb within layouts/application (2036.4ms)
2020-01-10T04:36:26 [I|app|72aa498e]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_remote_execution-1.8.2/app/views/job_invocations/index.html.erb within layouts/application (2156.0ms)

Also attaching production.log for the hour of the event

Cheers!
Aaron