Description of problem: During SmartState Analysis of RHOS VM, received multiple messages about failing to create snapshot Version-Release number of selected component (if applicable): 5.4.0.0.23.20150423131011_69b48fd How reproducible: Unsure Steps to Reproduce: 1. Perform SmartState Analysis on RHOS VM 2. 3. Actual results: Errors in evm.log Expected results: No errors, successful SmartState Analysis Additional info: evm.log excerpt: [----] E, [2015-04-28T15:59:20.575060 #2618:eb1ea0] ERROR -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) MIQ(MiqOpenStackInstance#create_evm_snapshot) instance_id=[85a986f2-59f2-4f72-bcf8-8f8bd [----] D, [2015-04-28T15:59:20.575191 #2618:eb1ea0] DEBUG -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) /var/www/miq/lib/OpenStackExtract/MiqOpenStackVm/MiqOpenStackInstance.rb:30:in `snapshot /var/www/miq/lib/OpenStackExtract/MiqOpenStackVm/MiqOpenStackInstance.rb:34:in `snapshot_image_id' /var/www/miq/lib/OpenStackExtract/MiqOpenStackVm/MiqOpenStackInstance.rb:47:in `create_evm_snapshot' /var/www/miq/vmdb/app/models/ems_openstack.rb:76:in `vm_create_evm_snapshot' /var/www/miq/vmdb/app/models/vm_scan.rb:56:in `call_snapshot_create' /var/www/miq/vmdb/app/models/job/state_machine.rb:29:in `signal' /var/www/miq/vmdb/app/models/miq_queue.rb:356:in `block in deliver' /opt/rh/ruby200/root/usr/share/ruby/timeout.rb:66:in `timeout' /var/www/miq/vmdb/app/models/miq_queue.rb:352:in `deliver' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:107:in `deliver_queue_message' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:135:in `deliver_message' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:152:in `block in do_work' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `loop' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `do_work' /var/www/miq/vmdb/lib/workers/worker_base.rb:323:in `block in do_work_loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `do_work_loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:141:in `run' /var/www/miq/vmdb/lib/workers/worker_base.rb:122:in `start' /var/www/miq/vmdb/lib/workers/worker_base.rb:23:in `start_worker' /var/www/miq/vmdb/lib/workers/bin/worker.rb:3:in `<top (required)>' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands/runner.rb:52:in `eval' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands/runner.rb:52:in `<top (required)>' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands.rb:64:in `require' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands.rb:64:in `<top (required)>' script/rails:6:in `require' script/rails:6:in `<main>' [----] E, [2015-04-28T15:59:20.575322 #2618:eb1ea0] ERROR -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) MIQ(EmsOpenstack#vm_create_evm_snapshot) vm=[test_instance_pwrctl_la9wABIa], error: unde [----] D, [2015-04-28T15:59:20.575396 #2618:eb1ea0] DEBUG -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) /var/www/miq/lib/OpenStackExtract/MiqOpenStackVm/MiqOpenStackInstance.rb:30:in `snapshot /var/www/miq/lib/OpenStackExtract/MiqOpenStackVm/MiqOpenStackInstance.rb:34:in `snapshot_image_id' /var/www/miq/lib/OpenStackExtract/MiqOpenStackVm/MiqOpenStackInstance.rb:47:in `create_evm_snapshot' /var/www/miq/vmdb/app/models/ems_openstack.rb:76:in `vm_create_evm_snapshot' /var/www/miq/vmdb/app/models/vm_scan.rb:56:in `call_snapshot_create' /var/www/miq/vmdb/app/models/job/state_machine.rb:29:in `signal' /var/www/miq/vmdb/app/models/miq_queue.rb:356:in `block in deliver' /opt/rh/ruby200/root/usr/share/ruby/timeout.rb:66:in `timeout' /var/www/miq/vmdb/app/models/miq_queue.rb:352:in `deliver' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:107:in `deliver_queue_message' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:135:in `deliver_message' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:152:in `block in do_work' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `loop' /var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `do_work' /var/www/miq/vmdb/lib/workers/worker_base.rb:323:in `block in do_work_loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `do_work_loop' /var/www/miq/vmdb/lib/workers/worker_base.rb:141:in `run' /var/www/miq/vmdb/lib/workers/worker_base.rb:122:in `start' /var/www/miq/vmdb/lib/workers/worker_base.rb:23:in `start_worker' /var/www/miq/vmdb/lib/workers/bin/worker.rb:3:in `<top (required)>' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands/runner.rb:52:in `eval' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands/runner.rb:52:in `<top (required)>' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands.rb:64:in `require' /opt/rh/cfme-gemset/bundler/gems/rails-8f014fba21f9/railties/lib/rails/commands.rb:64:in `<top (required)>' script/rails:6:in `require' script/rails:6:in `<main>' [----] E, [2015-04-28T15:59:20.575640 #2618:eb1ea0] ERROR -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) MIQ(scan-call_snapshot_create Failed to create evm snapshot with EMS. Error: [NoMethodEr [----] I, [2015-04-28T15:59:20.606311 #2618:eb1ea0] INFO -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) MIQ(Event.raise_evm_event): Event Raised [vm_scan_abort] [----] I, [2015-04-28T15:59:20.627290 #2618:eb1ea0] INFO -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) MIQ(Event.raise_evm_event): Alert for Event [vm_scan_abort] [----] I, [2015-04-28T15:59:20.627580 #2618:eb1ea0] INFO -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) MIQ(MiqAlert.evaluate_alerts) [vm_scan_abort] Target: VmOpenstack Name: [test_instance_p [----] E, [2015-04-28T15:59:20.636632 #2618:eb1ea0] ERROR -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) action-abort: job aborting, Failed to create evm snapshot with EMS. Error: [NoMethodErro [----] I, [2015-04-28T15:59:20.657978 #2618:eb1ea0] INFO -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) action-finished: job finished, Failed to create evm snapshot with EMS. Error: [NoMethodE [----] I, [2015-04-28T15:59:20.666449 #2618:eb1ea0] INFO -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) dispatch_finish: Dispatch Status is 'finished' [----] I, [2015-04-28T15:59:20.691268 #2618:eb1ea0] INFO -- : Q-task_id([d2df267c-ede0-11e4-b9c9-001a4a60db13]) MIQ(MiqQueue.delivered) Message id: [3642], State: [ok], Delivered in [1.798055503] sec VM is available with logfiles
Thom, do you have the actual logfiles? The snippet pasted into the bz has some end-of-line truncating that may be useful information. Also a pointer to your test environment would be helpful if possible. Thanks.
Supplied via IRC
I did see this message for this particular VM last week on Thursday but some time between then and today the VM in question was deleted from the OpenStack provider. None of the other VMs we have are exhibiting this issue and we cannot recreate it for new VMs. It is possible that the initial cause of this was environmental in nature although the code should handle the situation. I would like to remove this from the "blocker" list and keep this open to try to debug as a lower priority issue.
Agreed, did not reoccur on RHOS6.
Reoccured on RHOS6
Deferring to 5.5.4 since today is dev complete for 5.5.3
Changing the needing to Thom Carlin.
Changing back to dajo.
Closing.