Description of problem: setting certain types of filters can cause puma to consume all cpu Version-Release number of selected component (if applicable): 5.8.2 How reproducible: all the time Steps to Reproduce: 1.configure a report using a filter based on "EVM Custom Attributes: Name" and "EVM Custom Attributes: Value" 2. 3. Actual results: after saving changes, trying to edit the filter will result in the user looping and being unable to access the page. Attempts to access the report will also cause puma to consume all cpu on at least one thread Expected results: the filter tab can still be accessed and edited and the reports accessed. Additional info:
the issue presents itself after setting the filter ; accessing saved reports becomes impossible, so does editing the filter.
I installed gdb, yum install gdb and then followed the steps [1] to attach to the UI worker and retrieve a the backtrace from all ruby threads [1] https://github.com/ManageIQ/manageiq.org/pull/281 I managed to get a backtrace for the problematic 100% thread: eval:1:in `backtrace' eval:1:in `block in parse_params' eval:1:in `each' eval:1:in `parse_params' /var/www/miq/vmdb/lib/miq_expression/target.rb:12:in `match' /var/www/miq/vmdb/lib/miq_expression/target.rb:12:in `parse_params' /var/www/miq/vmdb/lib/miq_expression/tag.rb:15:in `parse' /opt/rh/cfme-gemset/bundler/gems/manageiq-ui-classic-35beb5e894ab/app/controllers/report_controller/reports/editor.rb:163:in `block in display_filter_details_for' /opt/rh/cfme-gemset/bundler/gems/manageiq-ui-classic-35beb5e894ab/app/controllers/report_controller/reports/editor.rb:163:in `select' /opt/rh/cfme-gemset/bundler/gems/manageiq-ui-classic-35beb5e894ab/app/controllers/report_controller/reports/editor.rb:163:in `display_filter_details_for' /opt/rh/cfme-gemset/bundler/gems/manageiq-ui-classic-35beb5e894ab/app/controllers/report_controller/reports/editor.rb:226:in `build_edit_screen' /opt/rh/cfme-gemset/bundler/gems/manageiq-ui-classic-35beb5e894ab/app/controllers/report_controller/reports/editor.rb:118:in `miq_report_edit' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/abstract_controller/base.rb:188:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal/rendering.rb:30:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/abstract_controller/callbacks.rb:20:in `block in process_action' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:126:in `call' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:455:in `call' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:101:in `__run_callbacks__' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:90:in `run_callbacks' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/abstract_controller/callbacks.rb:19:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal/rescue.rb:20:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/notifications.rb:164:in `block in instrument' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/notifications/instrumenter.rb:21:in `instrument' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/notifications.rb:164:in `instrument' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal/instrumentation.rb:30:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal/params_wrapper.rb:248:in `process_action' /opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/railties/controller_runtime.rb:18:in `process_action' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/abstract_controller/base.rb:126:in `process' /opt/rh/cfme-gemset/gems/actionview-5.0.3/lib/action_view/rendering.rb:30:in `process' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal.rb:190:in `dispatch' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_controller/metal.rb:262:in `dispatch' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/routing/route_set.rb:50:in `dispatch' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/routing/route_set.rb:32:in `serve' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/journey/router.rb:39:in `block in serve' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/journey/router.rb:26:in `each' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/journey/router.rb:26:in `serve' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/routing/route_set.rb:725:in `call' /opt/rh/cfme-gemset/gems/secure_headers-3.0.3/lib/secure_headers/middleware.rb:10:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/etag.rb:25:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/conditional_get.rb:25:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/head.rb:12:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:232:in `context' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:226:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/cookies.rb:613:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:97:in `__run_callbacks__' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:750:in `_run_call_callbacks' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/callbacks.rb:90:in `run_callbacks' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/callbacks.rb:36:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/remote_ip.rb:79:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call' /opt/rh/cfme-gemset/gems/railties-5.0.3/lib/rails/rack/logger.rb:36:in `call_app' /opt/rh/cfme-gemset/gems/railties-5.0.3/lib/rails/rack/logger.rb:26:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/request_id.rb:24:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call' /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' /opt/rh/cfme-gemset/gems/actionpack-5.0.3/lib/action_dispatch/middleware/executor.rb:12:in `call' /opt/rh/cfme-gemset/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call' /opt/rh/cfme-gemset/gems/railties-5.0.3/lib/rails/engine.rb:522:in `call' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/configuration.rb:224:in `call' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:561:in `handle_request' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:406:in `process_client' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:271:in `block in run' /opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/thread_pool.rb:111:in `block in spawn_thread'
Using that backtrace, I could reliably recreate 100% problem on the fine branch by running this in rails console: MiqExpression::Tag.parse("ManageIQ::Providers::CloudManager::Vm.miq_custom_attributes-name")
Note, I cannot recreate the rails console 100% cpu spin on the gaprindashvili or master branches so it appears to have been fixed.
Applying this code change seems to prevent the 100% cpu infinite loop: diff --git a/lib/miq_expression/tag.rb b/lib/miq_expression/tag.rb index 8f8b4fad4b..7e2be770ee 100644 --- a/lib/miq_expression/tag.rb +++ b/lib/miq_expression/tag.rb @@ -1,6 +1,6 @@ class MiqExpression::Tag < MiqExpression::Target REGEX = / -(?<model_name>([[:alnum:]]*(::)?)+) +(?<model_name>([[:alnum:]]*(::)?){4}) \.(?<associations>([a-z_]+\.)*) (?<namespace>\bmanaged|user_tag\b) -(?<column>[a-z]+[_[:alnum:]]+) From: https://github.com/ManageIQ/manageiq/pull/16211
Upstream fine PR: https://github.com/ManageIQ/manageiq/pull/16612
New commit detected on ManageIQ/manageiq/fine: https://github.com/ManageIQ/manageiq/commit/a9f25e8730011e7a4c7523bd194189975228ad18 commit a9f25e8730011e7a4c7523bd194189975228ad18 Author: Joe Rafaniello <jrafanie> AuthorDate: Wed Dec 6 17:11:12 2017 -0500 Commit: Joe Rafaniello <jrafanie> CommitDate: Wed Dec 6 17:15:49 2017 -0500 Limit number of '::' when parsing model https://bugzilla.redhat.com/show_bug.cgi?id=1519809 This will prevent an infinite loop inside regex when parsing strings like "ManageIQ::Providers::CloudManager::Vm.miq_custom_attributes-name" This is a manual partial backport of b19567af31ebb90cd0745de438354db987c17e98 which was in PR: https://github.com/ManageIQ/manageiq/pull/16211 Before this change, this will spin at 100% cpu in rails console: MiqExpression::Tag.parse("ManageIQ::Providers::CloudManager::Vm.miq_custom_attributes-name") After this change, it returns nil nearly immediately. lib/miq_expression/tag.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
I was able to verify this bug was fixed in 5.8.3.0 using the supplied report and also by executing the ruby command.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2018:0374
*** Bug 1544956 has been marked as a duplicate of this bug. ***