Bug 1386741

Summary: Scan through VC =>multiple instances of "[NoMethodError]: undefined method `key?' " errors
Product: Red Hat CloudForms Management Engine Reporter: Thomas Hennessy <thenness>
Component: SmartState AnalysisAssignee: Rich Oliveri <roliveri>
Status: CLOSED DUPLICATE QA Contact: Satyajit Bulage <sbulage>
Severity: medium Docs Contact:
Priority: medium    
Version: 5.7.0CC: bascar, cpelland, hsong, jhardy, obarenbo, thenness
Target Milestone: GA   
Target Release: cfme-future   
Hardware: x86_64   
OS: Linux   
Whiteboard: smartstate
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-07 15:57:12 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:
Attachments:
Description Flags
grep of one process that contains at least on occurance of the reported error
none
full set of appliance logs from install to data collection none

Description Thomas Hennessy 2016-10-19 14:36:29 UTC
Created attachment 1212176 [details]
grep of one process that contains at least on occurance of the reported error

Description of problem: Smartstate scan errors when attempting to scan VMware appliances thru the provider (ie, VC)


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


How reproducible: Alter the configuration file to scan VMware VMs thru the VC and then initiate scanning.


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:error + backtrace follows
=====
[----] E, [2016-10-17T14:45:34.293825 #11985:da7154] ERROR -- : [NoMethodError]: undefined method `key?' for nil:NilClass  Method:[rescue in scan_metadata]
[----] E, [2016-10-17T14:45:34.294117 #11985:da7154] ERROR -- : /opt/rh/rh-ruby23/root/usr/share/ruby/ostruct.rb:176:in `respond_to_missing?'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:381:in `respond_to?'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:381:in `init_with'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:374:in `revive'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:208:in `visit_Psych_Nodes_Mapping'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/visitor.rb:16:in `visit'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/visitor.rb:6:in `accept'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:32:in `accept'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:330:in `block in register_empty'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:330:in `each'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:330:in `register_empty'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:141:in `visit_Psych_Nodes_Sequence'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/visitor.rb:16:in `visit'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/visitor.rb:6:in `accept'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:32:in `accept'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:311:in `visit_Psych_Nodes_Document'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/visitor.rb:16:in `visit'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/visitor.rb:6:in `accept'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/visitors/to_ruby.rb:32:in `accept'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych/nodes/node.rb:38:in `to_ruby'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/psych-2.0.17/lib/psych.rb:253:in `load'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/coders/yaml_column.rb:24:in `load'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/type/serialized.rb:18:in `deserialize'
/opt/rh/cfme-gemset/gems/activemodel-5.0.0.1/lib/active_model/type/helpers/mutable.rb:6:in `cast'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute.rb:150:in `type_cast'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute.rb:38:in `value'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute.rb:123:in `changed_from_assignment?'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute.rb:55:in `changed?'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_mutation_tracker.rb:25:in `changed?'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_mutation_tracker.rb:9:in `block in changed_values'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_mutation_tracker.rb:8:in `each'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_mutation_tracker.rb:8:in `each_with_object'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_mutation_tracker.rb:8:in `changed_values'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_methods/dirty.rb:83:in `changed_attributes'
/opt/rh/cfme-gemset/gems/activemodel-5.0.0.1/lib/active_model/dirty.rb:146:in `changed'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_methods/dirty.rb:127:in `keys_for_partial_write'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_methods/dirty.rb:123:in `_create_record'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/callbacks.rb:302:in `block in _create_record'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:750:in `_run_create_callbacks'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/callbacks.rb:302:in `_create_record'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/timestamp.rb:68:in `_create_record'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/persistence.rb:534:in `create_or_update'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/callbacks.rb:298:in `block in create_or_update'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:126:in `call'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:455:in `call'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:750:in `_run_save_callbacks'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/callbacks.rb:298:in `create_or_update'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/persistence.rb:152:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/validations.rb:50:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/attribute_methods/dirty.rb:30:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/transactions.rb:324:in `block in save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/transactions.rb:395:in `block in with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `block in transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/connection_adapters/abstract/transaction.rb:189:in `within_new_transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/transactions.rb:211:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/transactions.rb:392:in `with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/transactions.rb:324:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/suppressor.rb:45:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/persistence.rb:51:in `create!'
/var/www/miq/vmdb/app/models/miq_queue.rb:124:in `put'
/var/www/miq/vmdb/app/models/miq_server/server_smart_proxy.rb:95:in `queue_call'
/var/www/miq/vmdb/app/models/mixins/scanning_mixin.rb:161:in `scan_metadata'
/var/www/miq/vmdb/app/models/vm_scan.rb:177:in `call_scan'
/var/www/miq/vmdb/app/models/vm_scan.rb:519:in `snapshot_complete'
/var/www/miq/vmdb/app/models/job/state_machine.rb:33:in `signal'
/var/www/miq/vmdb/app/models/vm_scan.rb:127:in `call_snapshot_create'
/var/www/miq/vmdb/app/models/job/state_machine.rb:33:in `signal'
/var/www/miq/vmdb/app/models/vm_scan.rb:85:in `check_policy_complete'
/var/www/miq/vmdb/app/models/miq_queue.rb:416:in `m_callback'
/var/www/miq/vmdb/app/models/miq_queue.rb:385:in `delivered'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:117:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:134:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:152:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:146:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:334:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:331:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:331:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:153:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:128:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:21:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:343:in `block in start'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:341:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:270:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:52:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:158:in `start'
/var/www/miq/vmdb/app/models/miq_server.rb:248: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>'

***

Comment 2 Thomas Hennessy 2016-10-19 14:41:00 UTC
Created attachment 1212178 [details]
full set of appliance logs from install to data collection

Comment 4 Thomas Hennessy 2016-10-20 19:19:37 UTC
the environment is the Raleigh GSS testing environment.  there is one VC and one ESX host and about 30 VMs.  Your ask regarding "May I have your environment?" is ambiguous.  If the information above does not satisfy your needs, please make specific requests and I'll answer them if I can.

Tom Hennessy

Comment 5 Thomas Hennessy 2016-10-20 19:21:28 UTC
the environment is the Raleigh GSS testing environment.  there is one VC and one ESX host and about 30 VMs.  Your ask regarding "May I have your environment?" is ambiguous.  If the information above does not satisfy your needs, please make specific requests and I'll answer them if I can.

Also, I have opened two different BZ's on problems discovered in this testing.

Tom Hennessy

Comment 9 Hui Song 2016-11-07 15:57:12 UTC
This issue is caused by a ruby bug: https://bugs.ruby-lang.org/issues/11884. Ruby version of 2.3.1 will solve the problem.

*** This bug has been marked as a duplicate of bug 1378447 ***