Description of problem:

When performing Smartstate Analysis on RHOS VM, receive unexpected messages in evm.log

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:

[----] I, [2015-04-28T12:11:31.215307 #2610:7efea0]  INFO -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(Vm-save_metadata) TaskId = [d68bf612-edc0-11e4-b9c9-001a4a60db13]
[----] E, [2015-04-28T12:11:31.217129 #2610:7efea0] ERROR -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(Vm-save_metadata) Processing xml for [system] [data is not permitted at state finish
[----] E, [2015-04-28T12:11:31.217297 #2610:7efea0] ERROR -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(Vm-save_metadata) Processing xml for [system] /var/www/miq/vmdb/app/models/job/state



Expected results:

No errors, successful SmartState Analysis

Additional info:

evm.log excerpt including traceback:
[----] I, [2015-04-28T12:11:31.207731 #2610:7efea0]  INFO -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(MiqQueue.deliver)    Message id: [1475], Delivering...
[----] I, [2015-04-28T12:11:31.215307 #2610:7efea0]  INFO -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(Vm-save_metadata) TaskId = [d68bf612-edc0-11e4-b9c9-001a4a60db13]
[----] E, [2015-04-28T12:11:31.217129 #2610:7efea0] ERROR -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(Vm-save_metadata) Processing xml for [system] [data is not permitted at state finish
[----] E, [2015-04-28T12:11:31.217297 #2610:7efea0] ERROR -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(Vm-save_metadata) Processing xml for [system] /var/www/miq/vmdb/app/models/job/state
/var/www/miq/vmdb/app/models/vm_or_template/scanning.rb:45:in `save_metadata'
/var/www/miq/vmdb/app/models/miq_queue.rb:354: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>'
[----] I, [2015-04-28T12:11:31.217510 #2610:7efea0]  INFO -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) Adding XML elements for [4] from [miq]
[----] I, [2015-04-28T12:11:31.251860 #2610:7efea0]  INFO -- : Q-task_id([d68bf612-edc0-11e4-b9c9-001a4a60db13]) MIQ(MiqQueue.delivered)  Message id: [1475], State: [ok], Delivered in [0.044114372] sec