Performance issues

Support
1

Problem:
The Foreman UI is often unusable and other access to Foreman times out.

Expected outcome:

Foreman and Proxy versions:
2.2.1 and was the same with 2.1.1.

Foreman and Proxy plugin versions:
Installed Packages

candlepin-3.1.22-1.el7.noarch
candlepin-selinux-3.1.22-1.el7.noarch
foreman-2.2.1-1.el7.noarch
foreman-cli-2.2.1-1.el7.noarch
foreman-debug-2.2.1-1.el7.noarch
foreman-dynflow-sidekiq-2.2.1-1.el7.noarch
foreman-installer-2.2.1-1.el7.noarch
foreman-installer-katello-2.2.1-1.el7.noarch
foreman-libvirt-2.2.1-1.el7.noarch
foreman-ovirt-2.2.1-1.el7.noarch
foreman-postgresql-2.2.1-1.el7.noarch
foreman-proxy-2.2.1-1.el7.noarch
foreman-release-2.2.1-1.el7.noarch
foreman-release-scl-7-3.el7.noarch
foreman-selinux-2.2.1-1.el7.noarch
foreman-service-2.2.1-1.el7.noarch
katello-3.17.1-1.el7.noarch
katello-certs-tools-2.7.1-2.el7.noarch
katello-client-bootstrap-1.7.5-1.el7.noarch
katello-common-3.17.1-1.el7.noarch
katello-debug-3.17.1-1.el7.noarch
katello-default-ca-1.0-1.noarch
katello-repos-3.17.1-1.el7.noarch
katello-selinux-3.4.0-1.el7.noarch
katello-server-ca-1.0-1.noarch
katello-service-3.14.1-1.el7.noarch
pulp-admin-client-2.21.4-2.el7.noarch
pulp-client-1.0-1.noarch
pulp-deb-plugins-1.10.2-1.el7.noarch
pulp-docker-plugins-3.2.8-1.el7.noarch
pulp-katello-1.0.3-1.el7.noarch
pulp-puppet-plugins-2.21.4-1.el7.noarch
pulp-puppet-tools-2.21.4-1.el7.noarch
pulp-rpm-admin-extensions-2.21.4-2.el7.noarch
pulp-rpm-plugins-2.21.4-2.el7.noarch
pulp-selinux-2.21.4-2.el7.noarch
pulp-server-2.21.4-2.el7.noarch
pulpcore-selinux-1.2.3-2.el7.x86_64
python-gofer-qpid-2.12.5-3.el7.noarch
python-pulp-bindings-2.21.4-2.el7.noarch
python-pulp-client-lib-2.21.4-2.el7.noarch
python-pulp-common-2.21.4-2.el7.noarch
python-pulp-deb-common-1.10.2-1.el7.noarch
python-pulp-docker-common-3.2.8-1.el7.noarch
python-pulp-oid_validation-2.21.4-2.el7.noarch
python-pulp-puppet-common-2.21.4-1.el7.noarch
python-pulp-repoauth-2.21.4-2.el7.noarch
python-pulp-rpm-common-2.21.4-2.el7.noarch
python-pulp-streamer-2.21.4-2.el7.noarch
python2-qpid-1.37.0-5.el7.noarch
python2-qpid-proton-0.32.0-2.el7.x86_64
python2-qpid-qmf-1.39.0-1.el7.x86_64
python3-pulp-2to3-migration-0.5.1-1.el7.noarch
python3-pulp-certguard-1.0.3-1.el7.noarch
python3-pulp-container-2.1.0-1.el7.noarch
python3-pulp-file-1.3.0-1.el7.noarch
python3-pulp-rpm-3.7.0-1.el7.noarch
python3-pulpcore-3.7.3-1.el7.noarch
qpid-cpp-client-1.39.0-1.el7.x86_64
qpid-cpp-client-devel-1.39.0-1.el7.x86_64
qpid-cpp-server-1.39.0-1.el7.x86_64
qpid-cpp-server-linearstore-1.39.0-1.el7.x86_64
qpid-dispatch-router-1.14.0-1.el7.x86_64
qpid-proton-c-0.32.0-2.el7.x86_64
qpid-qmf-1.39.0-1.el7.x86_64
qpid-tools-1.39.0-1.el7.noarch
rubygem-foreman_maintain-0.6.13-1.el7.noarch
tfm-rubygem-actioncable-6.0.3.1-1.el7.noarch
tfm-rubygem-actionmailbox-6.0.3.1-1.el7.noarch
tfm-rubygem-actionmailer-6.0.3.1-1.el7.noarch
tfm-rubygem-actionpack-6.0.3.1-1.el7.noarch
tfm-rubygem-actiontext-6.0.3.1-1.el7.noarch
tfm-rubygem-actionview-6.0.3.1-1.el7.noarch
tfm-rubygem-activejob-6.0.3.1-1.el7.noarch
tfm-rubygem-activemodel-6.0.3.1-1.el7.noarch
tfm-rubygem-activerecord-6.0.3.1-1.el7.noarch
tfm-rubygem-activerecord-import-1.0.0-2.el7.noarch
tfm-rubygem-activerecord-session_store-1.1.1-4.el7.noarch
tfm-rubygem-activestorage-6.0.3.1-1.el7.noarch
tfm-rubygem-activesupport-6.0.3.1-1.el7.noarch
tfm-rubygem-addressable-2.6.0-2.el7.noarch
tfm-rubygem-algebrick-0.7.3-7.el7.noarch
tfm-rubygem-amazing_print-1.1.0-1.el7.noarch
tfm-rubygem-ancestry-3.0.7-1.el7.noarch
tfm-rubygem-anemone-0.7.2-17.el7.noarch
tfm-rubygem-angular-rails-templates-1.1.0-1.el7.noarch
tfm-rubygem-ansi-1.5.0-2.el7.noarch
tfm-rubygem-apipie-bindings-0.4.0-1.el7.noarch
tfm-rubygem-apipie-dsl-2.2.9-1.el7.noarch
tfm-rubygem-apipie-params-0.0.5-4.el7.noarch
tfm-rubygem-apipie-rails-0.5.17-3.el7.noarch
tfm-rubygem-arel-9.0.0-4.el7.noarch
tfm-rubygem-audited-4.9.0-3.el7.noarch
tfm-rubygem-awesome_print-1.8.0-5.el7.noarch
tfm-rubygem-bcrypt-3.1.12-3.el7.x86_64
tfm-rubygem-builder-3.2.4-1.el7.noarch
tfm-rubygem-bundler_ext-0.4.1-5.el7.noarch
tfm-rubygem-clamp-1.1.2-6.el7.noarch
tfm-rubygem-coffee-rails-5.0.0-1.el7.noarch
tfm-rubygem-coffee-script-2.4.1-4.el7.noarch
tfm-rubygem-coffee-script-source-1.12.2-4.el7.noarch
tfm-rubygem-concurrent-ruby-1.1.6-2.el7.noarch
tfm-rubygem-concurrent-ruby-edge-0.6.0-2.fm2_1.el7.noarch
tfm-rubygem-connection_pool-2.2.2-2.el7.noarch
tfm-rubygem-crass-1.0.6-1.el7.noarch
tfm-rubygem-css_parser-1.4.7-4.el7.noarch
tfm-rubygem-daemons-1.2.3-6.el7.noarch
tfm-rubygem-deacon-1.0.0-4.el7.noarch
tfm-rubygem-deep_cloneable-3.0.0-3.el7.noarch
tfm-rubygem-deface-1.5.3-2.el7.noarch
tfm-rubygem-domain_name-0.5.20160310-4.el7.noarch
tfm-rubygem-dynflow-1.4.7-1.fm2_2.el7.noarch
tfm-rubygem-erubi-1.9.0-1.el7.noarch
tfm-rubygem-ethon-0.12.0-1.el7.noarch
tfm-rubygem-excon-0.76.0-1.el7.noarch
tfm-rubygem-execjs-2.7.0-4.el7.noarch
tfm-rubygem-facter-2.4.0-7.el7.x86_64
tfm-rubygem-faraday-0.15.4-2.el7.noarch
tfm-rubygem-fast_gettext-1.4.1-4.el7.noarch
tfm-rubygem-ffi-1.12.2-1.el7.x86_64
tfm-rubygem-fog-core-2.1.0-3.el7.noarch
tfm-rubygem-fog-json-1.2.0-3.el7.noarch
tfm-rubygem-fog-libvirt-0.7.0-2.el7.noarch
tfm-rubygem-fog-ovirt-1.2.5-1.el7.noarch
tfm-rubygem-fog-vsphere-3.4.0-1.el7.noarch
tfm-rubygem-fog-xml-0.1.2-8.el7.noarch
tfm-rubygem-foreman-tasks-3.0.1-1.fm2_2.el7.noarch
tfm-rubygem-foreman-tasks-core-0.3.4-1.fm2_1.el7.noarch
tfm-rubygem-foreman_ansible-6.0.0-1.fm2_2.el7.noarch
tfm-rubygem-foreman_ansible_core-3.0.4-1.fm2_2.el7.noarch
tfm-rubygem-foreman_remote_execution-4.1.0-1.fm2_2.el7.noarch
tfm-rubygem-foreman_remote_execution_core-1.3.1-1.el7.noarch
tfm-rubygem-formatador-0.2.1-12.el7.noarch
tfm-rubygem-friendly_id-5.3.0-1.el7.noarch
tfm-rubygem-fx-0.5.0-1.el7.noarch
tfm-rubygem-get_process_mem-0.2.1-4.el7.noarch
tfm-rubygem-gettext_i18n_rails-1.8.0-2.el7.noarch
tfm-rubygem-gitlab-sidekiq-fetcher-0.6.0-1.el7.noarch
tfm-rubygem-globalid-0.4.2-1.el7.noarch
tfm-rubygem-graphql-1.8.14-2.el7.noarch
tfm-rubygem-graphql-batch-0.3.10-2.el7.noarch
tfm-rubygem-gssapi-1.2.0-7.el7.noarch
tfm-rubygem-hammer_cli-2.2.1-1.el7.noarch
tfm-rubygem-hammer_cli_foreman-2.2.0-1.el7.noarch
tfm-rubygem-hammer_cli_foreman_bootdisk-0.3.0-1.el7.noarch
tfm-rubygem-hammer_cli_foreman_docker-0.0.7-1.el7.noarch
tfm-rubygem-hammer_cli_foreman_tasks-0.0.15-1.fm2_2.el7.noarch
tfm-rubygem-hammer_cli_katello-0.23.2-1.el7.noarch
tfm-rubygem-hashie-3.6.0-2.el7.noarch
tfm-rubygem-highline-1.7.8-5.el7.noarch
tfm-rubygem-http-cookie-1.0.2-4.el7.noarch
tfm-rubygem-i18n-1.8.2-1.el7.noarch
tfm-rubygem-ipaddress-0.8.0-12.el7.noarch
tfm-rubygem-jwt-2.2.1-2.el7.noarch
tfm-rubygem-kafo-5.0.1-1.el7.noarch
tfm-rubygem-kafo_parsers-1.1.0-3.el7.noarch
tfm-rubygem-kafo_wizards-0.0.1-4.el7.noarch
tfm-rubygem-katello-3.17.1-1.el7.noarch
tfm-rubygem-ldap_fluff-0.4.7-5.el7.noarch
tfm-rubygem-little-plugger-1.1.4-2.el7.noarch
tfm-rubygem-locale-2.0.9-14.el7.noarch
tfm-rubygem-logging-2.2.2-5.el7.noarch
tfm-rubygem-loofah-2.4.0-1.el7.noarch
tfm-rubygem-mail-2.7.1-1.el7.noarch
tfm-rubygem-marcel-0.3.3-1.el7.noarch
tfm-rubygem-method_source-0.9.2-1.el7.noarch
tfm-rubygem-mime-types-3.2.2-4.el7.noarch
tfm-rubygem-mime-types-data-3.2018.0812-4.el7.noarch
tfm-rubygem-mimemagic-0.3.5-1.el7.noarch
tfm-rubygem-mini_mime-1.0.2-1.el7.noarch
tfm-rubygem-mini_portile2-2.4.0-1.el7.noarch
tfm-rubygem-multi_json-1.14.1-2.el7.noarch
tfm-rubygem-multipart-post-2.0.0-2.el7.noarch
tfm-rubygem-mustermann-1.0.2-4.el7.noarch
tfm-rubygem-net-ldap-0.16.1-2.el7.noarch
tfm-rubygem-net-ping-2.0.1-4.el7.noarch
tfm-rubygem-net-scp-1.2.1-4.el7.noarch
tfm-rubygem-net-ssh-4.2.0-2.el7.noarch
tfm-rubygem-netrc-0.11.0-5.el7.noarch
tfm-rubygem-nio4r-2.5.2-1.el7.x86_64
tfm-rubygem-nokogiri-1.10.9-1.el7.x86_64
tfm-rubygem-oauth-0.5.4-4.el7.noarch
tfm-rubygem-optimist-3.0.0-2.el7.noarch
tfm-rubygem-ovirt-engine-sdk-4.3.0-1.el7.x86_64
tfm-rubygem-parse-cron-0.1.4-4.fm2_1.el7.noarch
tfm-rubygem-passenger-4.0.18-10.13.el7.x86_64
tfm-rubygem-passenger-native-4.0.18-10.13.el7.x86_64
tfm-rubygem-passenger-native-libs-4.0.18-10.13.el7.x86_64
tfm-rubygem-pg-1.1.4-3.el7.x86_64
tfm-rubygem-polyglot-0.3.5-2.el7.noarch
tfm-rubygem-powerbar-2.0.1-2.el7.noarch
tfm-rubygem-promise.rb-0.7.4-2.el7.noarch
tfm-rubygem-public_suffix-3.0.3-2.el7.noarch
tfm-rubygem-pulp_2to3_migration_client-0.5.0-1.el7.noarch
tfm-rubygem-pulp_ansible_client-0.3.0-1.el7.noarch
tfm-rubygem-pulp_certguard_client-1.0.2-1.el7.noarch
tfm-rubygem-pulp_container_client-2.0.0-1.el7.noarch
tfm-rubygem-pulp_docker_client-4.0.0b6.dev01562331743-1.el7.noarch
tfm-rubygem-pulp_file_client-1.2.0-1.el7.noarch
tfm-rubygem-pulp_rpm_client-3.6.2-1.el7.noarch
tfm-rubygem-pulpcore_client-3.6.0-1.el7.noarch
tfm-rubygem-puma-4.3.3-4.el7.x86_64
tfm-rubygem-qpid_messaging-1.38.0-1.el7.x86_64
tfm-rubygem-rabl-0.14.3-1.el7.noarch
tfm-rubygem-rack-2.2.3-1.el7.noarch
tfm-rubygem-rack-cors-1.0.2-2.el7.noarch
tfm-rubygem-rack-jsonp-1.3.1-9.el7.noarch
tfm-rubygem-rack-protection-2.0.3-4.el7.noarch
tfm-rubygem-rack-test-1.1.0-4.el7.noarch
tfm-rubygem-rails-6.0.3.1-1.el7.noarch
tfm-rubygem-rails-dom-testing-2.0.3-6.el7.noarch
tfm-rubygem-rails-html-sanitizer-1.3.0-1.el7.noarch
tfm-rubygem-rails-i18n-6.0.0-2.el7.noarch
tfm-rubygem-railties-6.0.3.1-1.el7.noarch
tfm-rubygem-rainbow-2.2.1-3.el7.noarch
tfm-rubygem-rake-compiler-1.0.7-3.el7.noarch
tfm-rubygem-rb-inotify-0.9.7-5.el7.noarch
tfm-rubygem-rbovirt-0.1.7-4.el7.noarch
tfm-rubygem-rbvmomi-2.2.0-3.el7.noarch
tfm-rubygem-record_tag_helper-1.0.1-3.el7.noarch
tfm-rubygem-redis-4.1.2-2.el7.noarch
tfm-rubygem-responders-3.0.0-3.el7.noarch
tfm-rubygem-rest-client-2.0.2-3.el7.noarch
tfm-rubygem-rkerberos-0.1.5-18.el7.x86_64
tfm-rubygem-roadie-3.4.0-3.el7.noarch
tfm-rubygem-roadie-rails-2.1.1-2.el7.noarch
tfm-rubygem-robotex-1.0.0-21.el7.noarch
tfm-rubygem-rsec-0.4.3-4.el7.noarch
tfm-rubygem-ruby-libvirt-0.7.1-1.el7.x86_64
tfm-rubygem-ruby2ruby-2.4.2-3.el7.noarch
tfm-rubygem-ruby_parser-3.10.1-3.el7.noarch
tfm-rubygem-rubyipmi-0.10.0-6.el7.noarch
tfm-rubygem-runcible-2.13.1-1.el7.noarch
tfm-rubygem-safemode-1.3.5-3.el7.noarch
tfm-rubygem-scoped_search-4.1.9-1.el7.noarch
tfm-rubygem-secure_headers-6.3.0-2.el7.noarch
tfm-rubygem-sequel-5.7.1-3.el7.noarch
tfm-rubygem-sexp_processor-4.10.0-6.el7.noarch
tfm-rubygem-sidekiq-5.2.7-3.el7.noarch
tfm-rubygem-sinatra-2.0.3-4.el7.noarch
tfm-rubygem-smart_proxy_ansible-3.0.1-6.fm2_2.el7.noarch
tfm-rubygem-smart_proxy_dynflow-0.2.4-6.fm2_2.el7.noarch
tfm-rubygem-smart_proxy_dynflow_core-0.2.6-1.fm2_2.el7.noarch
tfm-rubygem-smart_proxy_pulp-2.1.0-3.fm2_2.el7.noarch
tfm-rubygem-smart_proxy_remote_execution_ssh-0.3.0-4.fm2_2.el7.noarch
tfm-rubygem-sprockets-4.0.2-1.el7.noarch
tfm-rubygem-sprockets-rails-3.2.1-6.el7.noarch
tfm-rubygem-sqlite3-1.3.13-6.el7.x86_64
tfm-rubygem-sshkey-1.9.0-4.el7.noarch
tfm-rubygem-statsd-instrument-2.1.4-3.el7.noarch
tfm-rubygem-stomp-1.4.9-1.el7.noarch
tfm-rubygem-thor-1.0.1-2.el7.noarch
tfm-rubygem-thread_safe-0.3.6-5.el7.noarch
tfm-rubygem-tilt-2.0.8-4.el7.noarch
tfm-rubygem-typhoeus-1.3.1-1.el7.noarch
tfm-rubygem-tzinfo-1.2.6-1.el7.noarch
tfm-rubygem-unf-0.1.3-8.el7.noarch
tfm-rubygem-unf_ext-0.0.7.2-3.el7.x86_64
tfm-rubygem-unicode-0.4.4.4-3.el7.x86_64
tfm-rubygem-unicode-display_width-1.0.5-4.el7.noarch
tfm-rubygem-validates_lengths_from_database-0.5.0-7.el7.noarch
tfm-rubygem-webpack-rails-0.9.8-5.el7.noarch
tfm-rubygem-websocket-driver-0.7.1-1.el7.x86_64
tfm-rubygem-websocket-extensions-0.1.5-1.el7.noarch
tfm-rubygem-will_paginate-3.1.7-3.el7.noarch
tfm-rubygem-x-editable-rails-1.5.5-5.el7.noarch
tfm-rubygem-xmlrpc-0.3.0-2.el7.noarch
tfm-rubygem-zeitwerk-2.2.2-1.el7.noarch
tfm-runtime-6.1-3.el7.x86_64

Distribution and version:
CentOS Linux release 7.9.2009 (Core)

Other relevant data:

I have noticed some processes using a lot of CPU during the performance issues.

top - 10:52:53 up  1:42,  3 users,  load average: 1.67, 1.40, 1.18
Tasks: 393 total,   2 running, 391 sleeping,   0 stopped,   0 zombie
%Cpu(s): 24.7 us,  2.5 sy,  0.0 ni, 72.3 id,  0.2 wa,  0.0 hi,  0.4 si,  0.0 st
KiB Mem : 32779944 total,   165948 free, 21927072 used, 10686924 buff/cache
KiB Swap:  4190204 total,  4190204 free,        0 used. 10019820 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
24309 foreman   20   0 5509584   4.8g   6488 S 101.3 15.4  20:07.55 ruby
24314 foreman   20   0 4618408   3.9g   6488 S  48.2 12.4  20:58.11 ruby

# ps -ef
foreman  24309 23859 28 09:42 ?        00:20:30 puma: cluster worker 0: 23859 [foreman]

Please let me know if you need more info.

2

Anything interesting in /var/log/foreman/production.log during the performance issues? specific requests that are taking a long time or error messages?

3

I’ll try and take a look next time this is happening…typically the past few hours have been much better, even when the puma cluster worker processes are using a lot of CPU.
Is it normal for those processes to max out like that?

4

Hard to tell what exactly is happening just from the load - it may be some operation that is causing it, might be a bug that only occurs under certain conditions etc. We have seen a few reports of higher memory consumption since the switch to puma, for example in Foreman 2.0.0 - memory leak?. Perhaps playing with the number of workers and threads can lead to an improvement, but it would be good in any case to get the logs when there is an issue to identify if there is some operation that is gobbling up memory/cpu and can be optimized.

5

It seems to be performing better now - the ruby processes are almost always at 100% though.
The production.log is pretty noisy but i do see this kind of thing quite often.

2020-12-09T11:43:46 [E|app|5381ed62] RestClient::BadRequest: 400 Bad Request
 5381ed62 | Body: {"displayMessage":"Content access mode does not allow this request.","requestUuid":"606eaf64-46b5-4ae8-9611-d2ac9af33e04"}
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/abstract_response.rb:223:in `exception_with_response'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/abstract_response.rb:103:in `return!'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/request.rb:809:in `process_result'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/request.rb:725:in `block in transmit'
 5381ed62 | /opt/rh/rh-ruby25/root/usr/share/ruby/net/http.rb:910:in `start'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/request.rb:715:in `transmit'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/request.rb:145:in `execute'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/request.rb:52:in `execute'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.2/lib/restclient/resource.rb:51:in `get'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/app/lib/katello/resources/candlepin/proxy.rb:26:in `get'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:75:in `get'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/base.rb:195:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/rendering.rb:30:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:112:in `block in run_callbacks'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:35:in `repackage_message'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 5381ed62 | /usr/share/foreman/app/controllers/api/v2/base_controller.rb:181:in `disable_json_root'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 5381ed62 | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 5381ed62 | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 5381ed62 | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:139:in `run_callbacks'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/callbacks.rb:41:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/rescue.rb:22:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications.rb:180:in `block in instrument'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/notifications.rb:180:in `instrument'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/app/controllers/katello/concerns/api/api_controller.rb:40:in `process_action'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/abstract_controller/base.rb:136:in `process'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionview-6.0.3.1/lib/action_view/rendering.rb:39:in `process'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal.rb:190:in `dispatch'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_controller/metal.rb:254:in `dispatch'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:33:in `serve'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:49:in `block in serve'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `each'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `serve'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:834:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/engine.rb:527:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `public_send'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `method_missing'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/mapper.rb:19:in `block in <class:Constraints>'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/mapper.rb:48:in `serve'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:49:in `block in serve'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `each'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/journey/router.rb:32:in `serve'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/routing/route_set.rb:834:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/lib/katello/middleware/event_daemon.rb:10:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-dsl-2.2.9/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/static_dispatcher.rb:66:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/extractor/recorder.rb:137:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
 5381ed62 | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
 5381ed62 | /usr/share/foreman/lib/foreman/middleware/catch_json_parse_errors.rb:9:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/conditional_get.rb:27:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
 5381ed62 | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/cookies.rb:648:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/callbacks.rb:101:in `run_callbacks'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/actionable_exceptions.rb:17:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/rack/logger.rb:37:in `call_app'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/rack/logger.rb:28:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
 5381ed62 | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/request_id.rb:27:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/lib/katello/prevent_json_parsing.rb:12:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/executor.rb:14:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/static.rb:126:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.1/lib/action_dispatch/middleware/host_authorization.rb:76:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-6.3.0/lib/secure_headers/middleware.rb:11:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/engine.rb:527:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `public_send'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.1/lib/rails/railtie.rb:190:in `method_missing'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:74:in `block in call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `each'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/configuration.rb:228:in `call'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:682:in `handle_request'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:472:in `process_client'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/server.rb:328:in `block in run'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.3/lib/puma/thread_pool.rb:134:in `block in spawn_thread'
 5381ed62 | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2020-12-09T11:43:46 [I|app|5381ed62]   Rendering text template
2020-12-09T11:43:46 [I|app|5381ed62]   Rendered text template (Duration: 0.1ms | Allocations: 3)
2020-12-09T11:43:46 [I|app|5381ed62] Completed 400 Bad Request in 93ms (Views: 1.6ms | ActiveRecord: 4.5ms | Allocations: 4054)

Other than that its a bunch of stuff that doesn’t look too mucgh of an issue…
eg.

2020-12-09T11:47:23 [I|aud|a6b06c3f] Nic::Managed (53021) update event on identifier Exch_MICEX_589.1602, Exch_LDX_1012.1602
2020-12-09T11:47:23 [I|aud|a6b06c3f] Nic::Managed (53007) update event on attached_to Exch_MICEX_589, Exch_LDX_1012
2020-12-09T11:47:23 [I|aud|a6b06c3f] Nic::Managed (53007) update event on identifier Exch_MICEX_589.1604, Exch_LDX_1012.1604
2020-12-09T11:47:23 [I|aud|a6b06c3f] Nic::Managed (53009) update event on attached_to Exch_MICEX_589, Exch_LDX_1012
2020-12-09T11:47:23 [I|aud|a6b06c3f] Nic::Managed (53009) update event on identifier Exch_MICEX_589.23, Exch_LDX_1012.23
2020-12-09T11:47:24 [I|aud|a6b06c3f] Nic::Managed (53033) update event on attached_to Exch_MICEX_589, Exch_LDX_1012
2020-12-09T11:47:24 [I|aud|a6b06c3f] Nic::Managed (53033) update event on identifier Exch_MICEX_589.232, Exch_LDX_1012.232
2020-12-09T11:47:24 [I|aud|a6b06c3f] Nic::Managed (53005) update event on attached_to Exch_MICEX_589, Exch_LDX_1012
2020-12-09T11:47:24 [I|aud|a6b06c3f] Nic::Managed (53005) update event on identifier Exch_MICEX_589.233, Exch_LDX_1012.233
2020-12-09T11:47:24 [I|aud|a6b06c3f] Nic::Managed (53020) update event on attached_to Exch_MICEX_589, Exch_LDX_1012
2020-12-09T11:47:24 [I|aud|a6b06c3f] Nic::Managed (53020) update event on identifier Exch_MICEX_589.237, Exch_LDX_1012.237
2020-12-09T11:47:25 [I|app|a8ce3e1b] Started GET "/rhsm/consumers/d00eb81d-e7e7-4b6b-8b90-8090cdd28d01/certificates/serials" for 127.0.0.1 at 2020-12-09 11:47:25 +0000
2020-12-09T11:47:25 [I|app|a8ce3e1b] Processing by Katello::Api::Rhsm::CandlepinProxiesController#serials as JSON
2020-12-09T11:47:25 [I|app|a8ce3e1b]   Parameters: {"id"=>"d00eb81d-e7e7-4b6b-8b90-8090cdd28d01"}
2020-12-09T11:47:25 [I|aud|a6b06c3f] Nic::Managed (53003) update event on attached_to Exch_MICEX_589, Exch_LDX_1012
2020-12-09T11:47:25 [I|aud|a6b06c3f] Nic::Managed (53003) update event on identifier Exch_MICEX_589.2504, Exch_LDX_1012.2504
2020-12-09T11:47:25 [I|aud|a6b06c3f] Nic::Managed (53015) update event on attached_to Exch_MICEX_589, Exch_LDX_1012


2020-12-09T11:48:10 [I|app|019b381c] Started GET "/rhsm/" for 127.0.0.1 at 2020-12-09 11:48:10 +0000
2020-12-09T11:48:10 [I|app|4452bced] Started GET "/rhsm/consumers/13ec4d9e-c2ca-4044-8bf1-720c78c41b81/certificates/serials" for 127.0.0.1 at 2020-12-09 11:48:10 +0000
2020-12-09T11:48:10 [I|app|019b381c] Processing by Katello::Api::V2::RootController#rhsm_resource_list as JSON
2020-12-09T11:48:10 [I|app|019b381c]   Parameters: {"root"=>{}}
2020-12-09T11:48:10 [I|app|4452bced] Processing by Katello::Api::Rhsm::CandlepinProxiesController#serials as JSON
2020-12-09T11:48:10 [I|app|4452bced]   Parameters: {"id"=>"13ec4d9e-c2ca-4044-8bf1-720c78c41b81"}
2020-12-09T11:48:10 [I|app|737eaa86] Completed 200 OK in 775ms (Views: 0.4ms | ActiveRecord: 200.2ms | Allocations: 170491)
2020-12-09T11:48:10 [I|app|205ed815] Completed 200 OK in 896ms (Views: 1.4ms | ActiveRecord: 503.7ms | Allocations: 193464)
2020-12-09T11:48:10 [I|aud|045cfff9] Nic::Managed (50799) update event on attached_to Exch_JSE_1604, Exch_AQ_GS_718
2020-12-09T11:48:10 [I|aud|045cfff9] Nic::Managed (50799) update event on identifier Exch_JSE_1604.232, Exch_AQ_GS_718.232
2020-12-09T11:48:10 [I|app|019b381c]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/app/views/katello/api/v2/root/resource_list.json.rabl within katello/api/v2/layouts/collection
2020-12-09T11:48:10 [I|app|019b381c]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.1/app/views/katello/api/v2/root/resource_list.json.rabl within katello/api/v2/layouts/collection (Duration: 17.2ms | Allocations: 4026)
2020-12-09T11:48:10 [I|app|f71c65a1] Completed 200 OK in 822ms (Views: 1.4ms | ActiveRecord: 132.6ms | Allocations: 180365)
2020-12-09T11:48:10 [I|app|019b381c] Completed 200 OK in 196ms (Views: 54.8ms | ActiveRecord: 63.8ms | Allocations: 27389)

Unless anything in the logs don’t look right to you, perhaps we close this case for now and i’ll re-open or open a new case if the issue comes back…

6

This seems like you have some consumer(s) attempting to use simple content access mode while that mode is not allowed for them. I’m not familiar with the internals, perhaps someone from the @katello team can provide guidance regarding this?

These type of update events seem to indicate that the fact parser is creating or updating many interfaces, which I assume you don’t really care about in foreman. if that is indeed the case, you can add a rule to ignore them to the “Ignore interfaces with matching identifier” setting - something like Exch* will probably work. that should reduce quite a lot of load on your system.

7

After you filter them out, you also need to clean them from the DB.

https://theforeman.org/2018/03/foreman-117-fact-filtering.html

1 Like
8

Thanks i’ll give that filter a try.
We did try using simple content access mode a while back but it didn’t work well (or as expected, can’t quite remember the details) so switched back.

9

I think that’s a Candlepin response that’s complaining about the content access mode… you may want to try refreshing your manifest and see if that helps.

1 Like
10

I tried refreshing the manifest but still see those errors in the production log.
It doesn’t seem to be causing any problem as far as i can tell…

The interface filter is working though :+1:

I’ve not seen the same performance issues for a while so think we’re ok to close this one off.
Thanks for the help…

1 Like
11

Hi,

Sorry to open up an old ticket - we’re seeing high CPU usage on the 2 puma (ruby) processes again.
Is it possible to increase the number of Puma cluster workers?

Thanks
Rob

12

You can configure the number of workers via:

foreman-installer --foreman-service-puma-workers <# of workers desired>

You can also tune the min/max threads handled by each worker with:

--foreman-service-puma-threads-min
--foreman-service-puma-threads-max

Do keep in mind that this can affect the number of pools needed in database.yml. And that increasing the number of workers can potentially increase the number of connections to Postgres (which defaults to 100 and can be tuned).

13

Thanks - i’ll give it a try on our test system first.