Bug 1519809
| Summary: | setting certain types of filters can cause puma to consume all cpu | |||
|---|---|---|---|---|
| Product: | Red Hat CloudForms Management Engine | Reporter: | Felix Dewaleyne <fdewaley> | |
| Component: | Reporting | Assignee: | Joe Rafaniello <jrafanie> | |
| Status: | CLOSED ERRATA | QA Contact: | Niyaz Akhtar Ansari <nansari> | |
| Severity: | high | Docs Contact: | ||
| Priority: | high | |||
| Version: | 5.8.0 | CC: | cpelland, fdewaley, jhardy, jocarter, jrafanie, mfalesni, obarenbo, rspagnol, simaishi | |
| Target Milestone: | GA | Keywords: | ZStream | |
| Target Release: | 5.8.3 | |||
| Hardware: | All | |||
| OS: | All | |||
| Whiteboard: | ||||
| Fixed In Version: | 5.8.3.0 | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | ||
| Clone Of: | ||||
| : | 1549241 (view as bug list) | Environment: | ||
| Last Closed: | 2018-02-28 13:10:26 UTC | Type: | Bug | |
| Regression: | --- | Mount Type: | --- | |
| Documentation: | --- | CRM: | ||
| Verified Versions: | Category: | --- | ||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | ||
| Cloudforms Team: | CFME Core | Target Upstream Version: | ||
| Embargoed: | ||||
| Bug Depends On: | ||||
| Bug Blocks: | 1549241 | |||
|
Description
Felix Dewaleyne
2017-12-01 13:33:53 UTC
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. *** |