Fedora Account System
Red Hat Associate
Red Hat Customer
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: