Bug 1334684 - [[MiqPassword::MiqPasswordError]: can not decrypt v0_key encrypted string] encountered during phase [prepare_provision]
Summary: [[MiqPassword::MiqPasswordError]: can not decrypt v0_key encrypted string] en...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Provisioning
Version: 5.6.0
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: GA
: 5.6.0
Assignee: Drew Bomhof
QA Contact: Taras Lehinevych
URL:
Whiteboard: provisioning
Depends On:
Blocks: 1339315
TreeView+ depends on / blocked
 
Reported: 2016-05-10 10:37 UTC by ncatling
Modified: 2016-08-03 01:33 UTC (History)
7 users (show)

Fixed In Version: 5.6.0.8
Doc Type: Bug Fix
Doc Text:
Clone Of:
: 1339315 (view as bug list)
Environment:
Last Closed: 2016-06-29 16:01:00 UTC
Category: ---
Cloudforms Team: ---
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2016:1348 0 normal SHIPPED_LIVE CFME 5.6.0 bug fixes and enhancement update 2016-06-29 18:50:04 UTC

Description ncatling 2016-05-10 10:37:41 UTC
Description of problem:

Provisioning from private Azure images fails with:

ERROR -- : Q-task_id([miq_provision_1000000000014]) MIQ(ManageIQ::Providers::Azure::CloudManager::Provision#provision_error) [[MiqPassword::MiqPasswordError]: can not decrypt v0_key encrypted string] encountered during phase [prepare_provision]
ERROR -- : Q-task_id([miq_provision_1000000000014]) /var/www/miq/vmdb/gems/pending/util/miq-password.rb:39:in `rescue in decrypt'
/var/www/miq/vmdb/gems/pending/util/miq-password.rb:36:in `decrypt'


Version-Release number of selected component (if applicable):
cfme-vsphere-5.6.0.5-1.x86_64.vsphere.ova

How reproducible:


Steps to Reproduce:
1. Compute > Clouds > Instances
2. Lifecycle > Provision Instances
3. Complete customisation template user and password fields and submit

Actual results:

Provisioning fails with
[MiqPassword::MiqPasswordError]: can not decrypt v0_key encrypted string

Expected results:


Additional info:

This appears related https://github.com/ManageIQ/manageiq/issues/7285

Reviewing evm.log, root_password is correctly set in miq_provision_request but then incorrectly overwritten with the root_username value in miq_provision.

[----] D, [2016-05-10T05:13:12.355912 #3220:63798c] DEBUG -- : Q-task_id([miq_provision_request_1000000000021]) MIQ(MiqProvisionRequest#create_request_task) MiqProvisionRequest Attributes: [{"description"=>"Provision from [Microsoft.Compute/Images/mytemplates/ubuntu-osDisk] to [cfme###]", "userid"=>"admin", "options"=>{:initial_pass=>true, :src_vm_id=>[1000000000008, "Microsoft.Compute/Images/mytemplates/ubuntu-osDisk"], :miq_request_dialog_name=>"miq_provision_azure_dialogs_template", :customize_enabled=>["disabled"], :current_tab_key=>:requester, :owner_phone=>nil, :owner_country=>nil, :owner_phone_mobile=>nil, :owner_title=>nil, :owner_first_name=>"sd", :owner_manager=>nil, :owner_address=>nil, :owner_company=>nil, :owner_last_name=>"ffs", :owner_manager_mail=>nil, :owner_city=>nil, :owner_department=>nil, :owner_load_ldap=>nil, :owner_manager_phone=>nil, :owner_state=>nil, :owner_office=>nil, :owner_zip=>nil, :owner_email=>"dds", :request_notes=>nil, :vm_tags=>[], :placement_auto=>[true, 1], :resource_group=>[nil, nil], :cloud_network=>[nil, nil], :cloud_subnet=>[nil, nil], :security_groups=>[nil, nil], :number_of_vms=>[1, "1"], :vm_description=>nil, :vm_prefix=>nil, :vm_name=>"changeme", :schedule_type=>["immediately", "Immediately on Approval"], :schedule_time=>Wed, 11 May 2016 00:00:00 UTC +00:00, :retirement=>[0, "Indefinite"], :retirement_warn=>[604800, "1 Week"], :instance_type=>[1000000000002, "Standard_A1"], :customization_template_script=>nil, :dns_servers=>nil, :dns_suffixes=>nil, :addr_mode=>["dhcp", "DHCP"], :linux_host_name=>nil, :gateway=>nil, :linux_domain_name=>nil, :subnet_mask=>nil, :customization_template_id=>[nil, nil], :root_username=>"nicholas", :root_password=>"v2:{EsyQFAWFaiVpwqrfHHc/AQ==}", :hostname=>nil, :start_date=>"5/11/2016", :start_hour=>"00", :start_min=>"00", :src_vm_nics=>[], :src_vm_lans=>[], :src_ems_id=>[1000000000002, "My Azure"], :owner_group=>nil, :delivered_on=>2016-05-10 09:13:12 UTC, :requester_group=>"EvmGroup-super_administrator"}, "request_type"=>"template", "message"=>"VM Provisioning - Request Created", "status"=>"Ok", "source_id"=>1000000000008, "source_type"=>"VmOrTemplate", "destination_id"=>nil, "destination_type"=>nil, "tenant_id"=>1000000000001, "state"=>"pending"}]...

[----] I, [2016-05-10T05:13:41.663212 #3220:63798c]  INFO -- : Q-task_id([miq_provision_1000000000021]) MIQ(ManageIQ::Providers::Azure::CloudManager::Provision#prepare_for_clone_task) {:initial_pass=>true, :src_vm_id=>[1000000000008, "Microsoft.Compute/Images/mytemplates/ubuntu-osDisk"], :miq_request_dialog_name=>"miq_provision_azure_dialogs_template", :customize_enabled=>["disabled"], :current_tab_key=>:requester, :owner_phone=>nil, :owner_country=>nil, :owner_phone_mobile=>nil, :owner_title=>nil, :owner_first_name=>"sd", :owner_manager=>nil, :owner_address=>nil, :owner_company=>nil, :owner_last_name=>"ffs", :owner_manager_mail=>nil, :owner_city=>nil, :owner_department=>nil, :owner_load_ldap=>nil, :owner_manager_phone=>nil, :owner_state=>nil, :owner_office=>nil, :owner_zip=>nil, :owner_email=>"dds", :request_notes=>nil, :vm_tags=>[], :placement_auto=>[true, 1], :resource_group=>[1000000000001, "Api-Default-North-Europe"], :cloud_network=>[1000000000005, "MyVNET"], :cloud_subnet=>[1000000000005, "Subnet"], :security_groups=>[nil, nil], :number_of_vms=>[1, "1"], :vm_description=>nil, :vm_prefix=>nil, :vm_name=>"changeme", :schedule_type=>["immediately", "Immediately on Approval"], :schedule_time=>Wed, 11 May 2016 00:00:00 UTC +00:00, :retirement=>[0, "Indefinite"], :retirement_warn=>[604800, "1 Week"], :instance_type=>[1000000000002, "Standard_A1"], :customization_template_script=>nil, :dns_servers=>nil, :dns_suffixes=>nil, :addr_mode=>["dhcp", "DHCP"], :linux_host_name=>nil, :gateway=>nil, :linux_domain_name=>nil, :subnet_mask=>nil, :customization_template_id=>[nil, nil], :root_username=>"nicholas", :root_password=>"nicholas", :hostname=>nil, :start_date=>"5/11/2016", :start_hour=>"00", :start_min=>"00", :src_vm_nics=>[], :src_vm_lans=>[], :src_ems_id=>[1000000000002, "My Azure"], :owner_group=>nil, :delivered_on=>2016-05-10 09:13:12 UTC, :requester_group=>"EvmGroup-super_administrator", :pass=>1, :dns_domain=>nil, :vm_target_name=>"cfme020", :vm_target_hostname=>"cfme020", :placement_availability_zone=>[nil, nil], :dest_availability_zone=>[nil, nil]}

Full stack trace:

ERROR -- : Q-task_id([miq_provision_1000000000020]) MIQ(ManageIQ::Providers::Azure::CloudManager::Provision#provision_error) [[MiqPassword::MiqPasswordError]: can not decrypt v0_key encrypted string] encountered during phase [prepare_provision]
[----] E, [2016-05-10T04:50:47.108360 #1481:c79994] ERROR -- : Q-task_id([miq_provision_1000000000020]) /var/www/miq/vmdb/gems/pending/util/miq-password.rb:39:in `rescue in decrypt'
/var/www/miq/vmdb/gems/pending/util/miq-password.rb:36:in `decrypt'
/var/www/miq/vmdb/gems/pending/util/miq-password.rb:68:in `decrypt'
/var/www/miq/vmdb/app/models/manageiq/providers/azure/cloud_manager/provision/options_helper.rb:3:in `root_password'
/var/www/miq/vmdb/app/models/manageiq/providers/azure/cloud_manager/provision/cloning.rb:90:in `prepare_for_clone_task'
/var/www/miq/vmdb/app/models/miq_provision/state_machine.rb:16:in `prepare_provision'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal'
/var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/provision/state_machine.rb:17:in `prepare_volumes'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal'
/var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/provision/state_machine.rb:9:in `determine_placement'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17:in `signal'
/var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/provision/state_machine.rb:3:in `create_destination'
/var/www/miq/vmdb/app/models/miq_request_task/state_machine.rb:17: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:17:in `signal'
/var/www/miq/vmdb/app/models/miq_provision_task.rb:15:in `do_request'
/var/www/miq/vmdb/app/models/miq_request_task.rb:192:in `execute'
/var/www/miq/vmdb/app/models/miq_queue.rb:347:in `block in deliver'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:89:in `block in timeout'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `block in catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:104:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:343:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:106: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:346: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:344:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:274:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:154: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:173:in `start'
/var/www/miq/vmdb/app/models/miq_server.rb:264: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 7 Taras Lehinevych 2016-06-16 14:56:00 UTC
Verified in 5.6.0.10-rc2.1

Comment 9 errata-xmlrpc 2016-06-29 16:01:00 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2016:1348


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