Bug #28723
Updated by SlickNetAaron please_edit_me over 5 years ago
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 25-55 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 , #19742, 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. <pre><code class="text"> 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) </code></pre> The most recent event I dug into had severe timings: <pre><code class="text"> 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) </code></pre> Also attaching production.log for the hour of the event Cheers! Aaron