Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1514896 - [RHV] VM publish to a template for a locked VM generates exception in evm.log
Summary: [RHV] VM publish to a template for a locked VM generates exception in evm.log
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Providers
Version: 5.9.0
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: GA
: cfme-future
Assignee: Moti Asayag
QA Contact: Ilanit Stein
URL:
Whiteboard: rhev
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-11-19 10:07 UTC by Ilanit Stein
Modified: 2017-12-05 15:18 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-11-26 15:07:46 UTC
Category: Bug
Cloudforms Team: RHEVM


Attachments (Terms of Use)

Description Ilanit Stein 2017-11-19 10:07:13 UTC
Description of problem:
I tried to run VM publish to a template, for a VM in locked status.
(The VM was still under process of a previous run of Publish VM to a template)

The Request failed with a reasonable Error:
[EVM] VM [sealed_vm] Step [CheckProvisioned] Status [Error Creating Template] Message [[OvirtSDK4::Error]: Fault reason is "Operation Failed". Fault detail is "[Cannot add Template. VM is locked or still running, try again once VM is in the Down state....

However in evm.log, there is an exception, with a traceback,
while it should fail normally. 

ERROR in evm.log: 
 
[----] E, [2017-11-15T04:00:16.711630 #64626:96b130] ERROR -- : Q-task_id([miq_provision_8]) MIQ(ManageIQ::Providers::Redhat::InfraManager::Provision#provision_error) [[OvirtSDK4::Error]: Fault reason is "Operation Failed". Fault detail is "[Cannot add Template. VM is locked or still running, try again once VM is in the Down state.]". HTTP response code is 409.] encountered duri
ng phase [start_clone_task] 
[----] E, [2017-11-15T04:00:16.711882 #64626:96b130] ERROR -- : Q-task_id([miq_provision_8]) /opt/rh/rh-ruby23/root/usr/share/gems/gems/ovirt-engine-sdk-4.1.12/lib/ovirtsdk4/connection.rb:514:in `raise_error' 
/opt/rh/rh-ruby23/root/usr/share/gems/gems/ovirt-engine-sdk-4.1.12/lib/ovirtsdk4/service.rb:82:in `check_fault' 
/opt/rh/rh-ruby23/root/usr/share/gems/gems/ovirt-engine-sdk-4.1.12/lib/ovirtsdk4/service.rb:198:in `block in internal_add' 
/opt/rh/rh-ruby23/root/usr/share/gems/gems/ovirt-engine-sdk-4.1.12/lib/ovirtsdk4/service.rb:46:in `wait' 
/opt/rh/rh-ruby23/root/usr/share/gems/gems/ovirt-engine-sdk-4.1.12/lib/ovirtsdk4/service.rb:201:in `internal_add' 
/opt/rh/rh-ruby23/root/usr/share/gems/gems/ovirt-engine-sdk-4.1.12/lib/ovirtsdk4/services.rb:25111:in `add' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/ovirt_services/strategies/v4.rb:446:in `make_template' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/ovirt_services/strategies/v4.rb:227:in `block in make_template' 
/var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:15:in `block in with_provider_object' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/api_integration.rb:96:in `with_provider_connection' 
/var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:12:in `with_provider_object' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/ovirt_services/strategies/v4.rb:226:in `make_template' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/provision/cloning.rb:87:in `start_clone' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/provision/state_machine.rb:16:in `start_clone_task' 
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:21:in `signal' 
/var/www/miq/vmdb/app/models/miq_provision/state_machine.rb:18:in `prepare_provision' 
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:21:in `signal' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/provision/state_machine.rb:9:in `determine_placement' 
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:21:in `signal' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-ovirt-deff16d97491/app/models/manageiq/providers/redhat/infra_manager/provision/state_machine.rb:3:in `create_destination' 
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:21:in `signal' 
/var/www/miq/vmdb/app/models/miq_provision/state_machine.rb:4:in `run_provision' 
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:21:in `signal' 
/var/www/miq/vmdb/app/models/miq_provision_task.rb:14:in `do_request' 
/var/www/miq/vmdb/app/models/miq_request_task.rb:194:in `execute' 
/var/www/miq/vmdb/app/models/miq_queue.rb:449:in `block in dispatch_method' 
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:91:in `block in timeout' 
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `block in catch' 
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch' 
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch' 
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:106:in `timeout' 
/var/www/miq/vmdb/app/models/miq_queue.rb:448:in `dispatch_method' 
/var/www/miq/vmdb/app/models/miq_queue.rb:425:in `block in deliver' 
/var/www/miq/vmdb/app/models/user.rb:253:in `with_user_group' 
/var/www/miq/vmdb/app/models/miq_queue.rb:425:in `deliver' 
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:104: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:329:in `block in do_work_loop' 
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `loop' 
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326: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:127:in `start' 
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:22:in `start_worker' 
/var/www/miq/vmdb/app/models/miq_worker.rb:357:in `block in start_runner_via_fork' 
/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:355:in `start_runner_via_fork' 
/var/www/miq/vmdb/app/models/miq_worker.rb:349:in `start_runner' 
/var/www/miq/vmdb/app/models/miq_worker.rb:396:in `start' 
/var/www/miq/vmdb/app/models/miq_worker.rb:266:in `start_worker' 
/var/www/miq/vmdb/app/models/miq_worker.rb:153:in `block in sync_workers' 
/var/www/miq/vmdb/app/models/miq_worker.rb:153:in `times' 
/var/www/miq/vmdb/app/models/miq_worker.rb:153:in `sync_workers' 
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:53: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/worker_management/monitor.rb:22:in `monitor_workers' 
/var/www/miq/vmdb/app/models/miq_server.rb:329:in `block in monitor' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-f1c90023a2e3/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-f1c90023a2e3/lib/gems/pending/util/extensions/miq-benchmark.rb:28:in `realtime_block' 
/var/www/miq/vmdb/app/models/miq_server.rb:329:in `monitor' 
/var/www/miq/vmdb/app/models/miq_server.rb:351:in `block (2 levels) in monitor_loop' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-f1c90023a2e3/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store' 
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-f1c90023a2e3/lib/gems/pending/util/extensions/miq-benchmark.rb:35:in `realtime_block' 
/var/www/miq/vmdb/app/models/miq_server.rb:351:in `block in monitor_loop' 
/var/www/miq/vmdb/app/models/miq_server.rb:350:in `loop' 
/var/www/miq/vmdb/app/models/miq_server.rb:350:in `monitor_loop' 
/var/www/miq/vmdb/app/models/miq_server.rb:234: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, [2017-11-15T04:00:16.796638 #64626:96b130]  INFO -- : Q-task_id([miq_provision_8]) Starting Phase <finish> 
[----] I, [2017-11-15T04:00:16.815462 #64626:96b130]  INFO -- : Q-task_id([miq_provision_8]) MIQ(MiqQueue#delivered) Message id: [9576], State: [ok], Delivered in [0.967251494] seconds 
[----] I, [2017-11-15T04:00:16.820182 #64626:96b130]  INFO -- : Q-task_id([miq_provision_8]) MIQ(MiqQueue#m_callback) Message id: [9576], Invoking Callback with args: ["ok", "Message delivered successfully", "nil"]

Version-Release number of selected component (if applicable):
CFMe-5.9.0.8/RHV-4.1.7

How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:


Note You need to log in before you can comment on or make changes to this bug.