Bug 1507131

Summary: MIQ(MiqServer#monitor) can't modify frozen Hash after UI worker restarts
Product: Red Hat CloudForms Management Engine Reporter: Jared Deubel <jdeubel>
Component: ApplianceAssignee: Joe Rafaniello <jrafanie>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Dave Johnson <dajohnso>
Severity: medium Docs Contact:
Priority: medium    
Version: 5.7.0CC: abellott, duhlmann, ext.jan.hladik, jdeubel, jhardy, jrafanie, obarenbo, rspagnol, smallamp, tuado
Target Milestone: GA   
Target Release: cfme-future   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1781202 (view as bug list) Environment:
Last Closed: 2019-08-23 20:15:02 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1781202    

Description Jared Deubel 2017-10-27 19:04:04 UTC
Description of problem:

After several issues where the UI has locked up I found this in the error log which seems to be about the same time of the UI lockup.

[----] E, [2017-10-25T11:41:29.352252 #2528:b87130] ERROR -- : MIQ(MiqServer#monitor) can't modify frozen Hash
[----] E, [2017-10-25T11:41:29.352496 #2528:b87130] ERROR -- : [RuntimeError]: can't modify frozen Hash  Method:[rescue in monitor]
[----] E, [2017-10-25T11:41:29.352597 #2528:b87130] ERROR -- : /opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/attribute_set.rb:53:in `write_from_user'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/attribute_methods/write.rb:50:in `write_attribute_with_type_cast'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/attribute_methods/write.rb:32:in `write_attribute'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/attribute_methods/write.rb:20:in `__temp__c6163747f5865616274726561647='
/opt/rh/cfme-gemset/gems/activemodel-5.0.2/lib/active_model/attribute_assignment.rb:46:in `public_send'
/opt/rh/cfme-gemset/gems/activemodel-5.0.2/lib/active_model/attribute_assignment.rb:46:in `_assign_attribute'
/opt/rh/cfme-gemset/gems/activemodel-5.0.2/lib/active_model/attribute_assignment.rb:40:in `block in _assign_attributes'
/opt/rh/cfme-gemset/gems/activemodel-5.0.2/lib/active_model/attribute_assignment.rb:39:in `each'
/opt/rh/cfme-gemset/gems/activemodel-5.0.2/lib/active_model/attribute_assignment.rb:39:in `_assign_attributes'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/attribute_assignment.rb:26:in `_assign_attributes'
/opt/rh/cfme-gemset/gems/activemodel-5.0.2/lib/active_model/attribute_assignment.rb:33:in `assign_attributes'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/persistence.rb:266:in `block in update'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/transactions.rb:395:in `block in with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `block in transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/connection_adapters/abstract/transaction.rb:189:in `within_new_transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/transactions.rb:211:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/transactions.rb:392:in `with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/persistence.rb:265:in `update'
/var/www/miq/vmdb/app/models/miq_server/worker_management/heartbeat.rb:90:in `validate_heartbeat'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor/validation.rb:11:in `validate_worker'
/var/www/miq/vmdb/app/models/miq_server/worker_management/heartbeat.rb:76:in `block in post_message_for_workers'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/relation/delegation.rb:38:in `each'
/opt/rh/cfme-gemset/gems/activerecord-5.0.2/lib/active_record/relation/delegation.rb:38:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/heartbeat.rb:66:in `post_message_for_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:32:in `block in monitor_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:28:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:28:in `monitor_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:346:in `block in monitor'
/var/www/miq/vmdb/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/var/www/miq/vmdb/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:346:in `monitor'
/var/www/miq/vmdb/app/models/miq_server.rb:368:in `block (2 levels) in monitor_loop'
/var/www/miq/vmdb/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/var/www/miq/vmdb/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:368:in `block in monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:367:in `loop'
/var/www/miq/vmdb/app/models/miq_server.rb:367:in `monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:250:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:65:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:92:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'
[----] I, [2017-10-25T11:41:29.352689 #2528:b87130]  INFO -- : MIQ(MiqServer#monitor) Reconnecting to database after error...
[----] I, [2017-10-25T11:41:29.385958 #2528:b87130]  INFO -- : MIQ(MiqServer#monitor) Reconnecting to database after error...Successful

Version-Release number of selected component (if applicable):
5.7

Comment 4 Joe Rafaniello 2018-02-23 20:02:25 UTC
Do we have more information about recreating this Jared?  Can it be closed if not?  I'm not quite sure how this could occur.

Comment 6 drew uhlmann 2018-04-24 13:44:51 UTC
Just in case anyone sees this again, I got around it by checking to make sure that the attribute being written hasn't already been destroyed. (the attribute setter in /Users/duhlmann/.rvm/gems/ruby-2.3.4/gems/activerecord-5.0.7/lib/active_record/attribute_methods/write.rb). Seems to only be a ruby 2.3 issue.

Comment 7 Jan Hladik 2019-12-09 16:22:06 UTC
We have same issue, while calling API
[----] E, [2019-12-09T18:03:33.374833 #3565:c44f50] ERROR -- : MIQ(MiqServer#monitor) can't modify frozen Hash
[----] E, [2019-12-09T18:03:33.374990 #3565:c44f50] ERROR -- : [RuntimeError]: can't modify frozen Hash  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2019-12-09T18:03:33.375050 #3565:c44f50] ERROR -- : /opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/attribute_set.rb:53:in `write_from_user'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/attribute_methods/write.rb:50:in `write_attribute_with_type_cast'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/attribute_methods/write.rb:32:in `write_attribute'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/attribute_methods/write.rb:20:in `__temp__c6163747f5865616274726561647='
/opt/rh/cfme-gemset/gems/activemodel-5.0.7.2/lib/active_model/attribute_assignment.rb:46:in `public_send'
/opt/rh/cfme-gemset/gems/activemodel-5.0.7.2/lib/active_model/attribute_assignment.rb:46:in `_assign_attribute'
/opt/rh/cfme-gemset/gems/activemodel-5.0.7.2/lib/active_model/attribute_assignment.rb:40:in `block in _assign_attributes'
/opt/rh/cfme-gemset/gems/activemodel-5.0.7.2/lib/active_model/attribute_assignment.rb:39:in `each'
/opt/rh/cfme-gemset/gems/activemodel-5.0.7.2/lib/active_model/attribute_assignment.rb:39:in `_assign_attributes'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/attribute_assignment.rb:26:in `_assign_attributes'
/opt/rh/cfme-gemset/gems/activemodel-5.0.7.2/lib/active_model/attribute_assignment.rb:33:in `assign_attributes'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/persistence.rb:274:in `block in update'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/transactions.rb:395:in `block in with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `block in transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract/transaction.rb:189:in `within_new_transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/transactions.rb:211:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/transactions.rb:392:in `with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/persistence.rb:273:in `update'
/var/www/miq/vmdb/app/models/miq_server/worker_management/heartbeat.rb:75:in `validate_heartbeat'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor/validation.rb:11:in `validate_worker'
/var/www/miq/vmdb/app/models/miq_server/worker_management/heartbeat.rb:61:in `block in post_message_for_workers'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation/delegation.rb:38:in `each'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation/delegation.rb:38:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/heartbeat.rb:51:in `post_message_for_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:32:in `block in monitor_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:28:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:28:in `monitor_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:339:in `block in monitor'
/opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-4ccebc6545f4/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-4ccebc6545f4/lib/gems/pending/util/extensions/miq-benchmark.rb:28:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:339:in `monitor'
/var/www/miq/vmdb/app/models/miq_server.rb:380:in `block (2 levels) in monitor_loop'
/opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-4ccebc6545f4/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-4ccebc6545f4/lib/gems/pending/util/extensions/miq-benchmark.rb:35:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:380:in `block in monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:379:in `loop'
/var/www/miq/vmdb/app/models/miq_server.rb:379:in `monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:241:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:27:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:48:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'
[----] I, [2019-12-09T18:03:33.375091 #3565:c44f50]  INFO -- : MIQ(MiqServer#monitor) Reconnecting to database after error...
[----] I, [2019-12-09T18:03:33.378014 #3792:c44f50]  INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 4.

Comment 8 Joe Rafaniello 2019-12-09 17:25:20 UTC
Hi Jan,

Please see the other comment and please followup here:

https://bugzilla.redhat.com/show_bug.cgi?id=1781202#c4

For now, please increase your web service worker count and memory threshold.  We'll continue to look at the cause of the side effect error "can't modify frozen hash".  We should also figure out why the memory growth is now happening or if something recently changed to cause this.

Comment 9 Red Hat Bugzilla 2023-09-14 04:10:54 UTC
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 1000 days