Unknown error during AWS Provisioning

[kTipSSIoYv]

I get the below error in logs when provisioning AWS instances. The provisioning continues and succeeds without any issues though.

This is on latest Morphy release.

sh-4.4# tail -f /var/www/miq/vmdb/log/automation.log  | grep -i error
[----] E, [2022-07-12T08:21:17.216732 #305:2ad7154dfa8c] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) The following error occurred during instance method <eligible_resources> for AR object <#<ManageIQ::Providers::Amazon::CloudManager::Provision id: 2127, description: "Provision from [amzn2-ami-kernel-5.10-hvm-2.0.2022...", state: "queued", request_type: "template", userid: "admin", options: {:initial_pass=>true, :service_template_request=>false, :miq_request_dialog_name=>"miq_provision_amazon_dialogs_template", :customize_enabled=>["enabled"], :requester_enabled=>["disabled"], :purpose_enabled=>["disabled"], :current_tab_key=>:schedule, :owner_phone=>nil, :owner_country=>nil, :owner_phone_mobile=>nil, :owner_title=>nil, :owner_first_name=>nil, :owner_manager=>nil, :owner_address=>nil, :owner_company=>nil, :owner_last_name=>nil, :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=>nil, :request_notes=>nil, :vm_tags=>[], :placement_auto=>[false, 0], :placement_availability_zone=>"2", :cloud_network=>"11", :cloud_subnet=>"13", :security_groups=>"167", :floating_ip_address=>[nil, nil], :number_of_vms=>1, :vm_description=>nil, :vm_prefix=>nil, :vm_name=>"Ubuntu", :schedule_type=>["immediately", "Immediately on Approval"], :schedule_time=>Tue, 12 Jul 2022 00:00:00 UTC +00:00, :retirement=>[0, "Indefinite"], :retirement_warn=>[604800, "1 Week"], :instance_type=>"185", :guest_access_key_pair=>"118", :monitoring=>["basic", "Basic"], :dns_servers=>nil, :dns_suffixes=>nil, :addr_mode=>["dhcp", "DHCP"], :linux_host_name=>"Ubuntu", :gateway=>nil, :linux_domain_name=>nil, :subnet_mask=>nil, :customization_template_script=>nil, :root_password=>nil, :hostname=>nil, :start_date=>"7/12/2022", :start_hour=>"00", :start_min=>"00", :src_vm_id=>"933", :name=>"AWS Ec2 Provisioning 2 ", :description=>nil, :long_description=>nil, :provision_cost=>nil, :display=>true, :catalog_id=>"1", :dialog_id=>"12", :st_prov_type=>"amazon", :tenant_ids=>[], :zone_id=>"2", :currency=>nil, :code_currency=>"Price / Month", :price=>nil, :retire_fqname=>"/Service/Retirement/StateMachines/ServiceRetirement/Default", :reconfigure_fqname=>nil, :fqname=>"/Service/Provisioning/StateMachines/ServiceProvision_Template/CatalogItemInitialization", :available_dialogs=>{1=>"Transform VM", 3=>"Choose Credentials", 4=>"Testing-temp", 10=>"Ec2 - Delete Tags", 7=>"Ec2 - Create Tags", 6=>"Ec2 - Update Tags", 11=>"Azure Provisioning", 5=>"EC2 Provisioning_old", 2=>"EC2 Provisioning_temp", 12=>"EC2 Provisioning"}, :service_type=>"atomic", :src_vm_nics=>[], :src_vm_lans=>[], :src_ems_id=>[2, "AWS"], :requester_group=>"EvmGroup-super_administrator", :pass=>0, :miq_force_unique_name=>[true, 1], :service_guid=>"76976542-03e5-45aa-a7e9-b4ad00e458c0", :service_resource_id=>1516, :owner_group=>"EvmGroup-super_administrator", :dns_domain=>nil, :vm_target_name=>"Ubuntu747", :vm_target_hostname=>"Ubuntu", :dialog_number_of_vms=>1, :dialog_vm_name=>"Ubuntu", :dialog_src_vm_id=>"933", :dialog_instance_type=>"185", :dialog_cloud_network=>"11", :dialog_placement_availability_zone=>"2", :dialog_guest_access_key_pair=>"118", :dialog_security_groups=>"167", :dialog_cloud_subnet=>"13", :run_ansible_tower_job=>0, :dialog_run_ansible_tower_job=>0, :ansible_tower_provider=>28, :dialog_ansible_tower_provider=>28, :job_template_id=>["118"], :dialog_job_template_id=>["118"], :job_credentials=>3, :dialog_job_credentials=>3, :param_ansible_ssh_user=>"ec2-user", :dialog_param_ansible_ssh_user=>"ec2-user", :sg_create_new=>0, :dialog_sg_create_new=>0, :sg_ssh_cidr=>"0.0.0.0/0", :dialog_sg_ssh_cidr=>"0.0.0.0/0", :create_sg_rules=>0, :dialog_create_sg_rules=>0, :executed_on_servers=>[5]}, created_on: "2022-07-12 08:20:15", updated_on: "2022-07-12 08:21:14", message: "State Machine Initializing", status: "Ok", type: "ManageIQ::Providers::Amazon::CloudManager::Provisi...", miq_request_id: 833, source_id: 933, source_type: "VmOrTemplate", destination_id: nil, destination_type: nil, miq_request_task_id: 2126, phase: nil, phase_context: {}, tenant_id: 1, cancelation_status: nil, conversion_host_id: nil>>
[----] E, [2022-07-12T08:21:17.219154 #305:2ad7154dfa8c] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) MiqAeServiceModelBase.ar_method raised: <NoMethodError>: <undefined method `to_a' for "167":String
[----] E, [2022-07-12T08:21:17.219296 #305:2ad7154dfa8c] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) /opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-amazon-bfa31d559f81/app/models/manageiq/providers/amazon/cloud_manager/provision_workflow.rb:63:in `security_group_to_availability_zones'
[----] E, [2022-07-12T08:21:17.219698 #305:2ad7154dfa8c] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) MiqAeServiceModelBase.ar_method raised: <NoMethodError>: <undefined method `to_a' for "167":String
[----] E, [2022-07-12T08:21:17.219826 #305:2ad7154dfa8c] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) /opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-amazon-bfa31d559f81/app/models/manageiq/providers/amazon/cloud_manager/provision_workflow.rb:63:in `security_group_to_availability_zones'
[----] I, [2022-07-12T08:21:17.221792 #305:2ad7146376b0]  INFO -- automation: Q-task_id([r833_miq_provision_2127]) <AEMethod object_walker> object_walker#86314DDC:[2] !!! MiqAeServiceManageIQ_Providers_Amazon_CloudManager_Provision association 'eligible_availability_zones' throws a NoMethodError exception when accessed (product bug?) !!!
[----] E, [2022-07-12T08:21:17.247928 #305:2ad7146376b0] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) The following error occurred during instance method <eligible_resources> for AR object <#<ManageIQ::Providers::Amazon::CloudManager::Provision id: 2127, description: "Provision from [amzn2-ami-kernel-5.10-hvm-2.0.2022...", state: "queued", request_type: "template", userid: "admin", options: {:initial_pass=>true, :service_template_request=>false, :miq_request_dialog_name=>"miq_provision_amazon_dialogs_template", :customize_enabled=>["enabled"], :requester_enabled=>["disabled"], :purpose_enabled=>["disabled"], :current_tab_key=>:schedule, :owner_phone=>nil, :owner_country=>nil, :owner_phone_mobile=>nil, :owner_title=>nil, :owner_first_name=>nil, :owner_manager=>nil, :owner_address=>nil, :owner_company=>nil, :owner_last_name=>nil, :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=>nil, :request_notes=>nil, :vm_tags=>[], :placement_auto=>[false, 0], :placement_availability_zone=>"2", :cloud_network=>"11", :cloud_subnet=>"13", :security_groups=>"167", :floating_ip_address=>[nil, nil], :number_of_vms=>1, :vm_description=>nil, :vm_prefix=>nil, :vm_name=>"Ubuntu", :schedule_type=>["immediately", "Immediately on Approval"], :schedule_time=>Tue, 12 Jul 2022 00:00:00 UTC +00:00, :retirement=>[0, "Indefinite"], :retirement_warn=>[604800, "1 Week"], :instance_type=>"185", :guest_access_key_pair=>"118", :monitoring=>["basic", "Basic"], :dns_servers=>nil, :dns_suffixes=>nil, :addr_mode=>["dhcp", "DHCP"], :linux_host_name=>"Ubuntu", :gateway=>nil, :linux_domain_name=>nil, :subnet_mask=>nil, :customization_template_script=>nil, :root_password=>nil, :hostname=>nil, :start_date=>"7/12/2022", :start_hour=>"00", :start_min=>"00", :src_vm_id=>"933", :name=>"AWS Ec2 Provisioning 2 ", :description=>nil, :long_description=>nil, :provision_cost=>nil, :display=>true, :catalog_id=>"1", :dialog_id=>"12", :st_prov_type=>"amazon", :tenant_ids=>[], :zone_id=>"2", :currency=>nil, :code_currency=>"Price / Month", :price=>nil, :retire_fqname=>"/Service/Retirement/StateMachines/ServiceRetirement/Default", :reconfigure_fqname=>nil, :fqname=>"/Service/Provisioning/StateMachines/ServiceProvision_Template/CatalogItemInitialization", :available_dialogs=>{1=>"Transform VM", 3=>"Choose Credentials", 4=>"Testing-temp", 10=>"Ec2 - Delete Tags", 7=>"Ec2 - Create Tags", 6=>"Ec2 - Update Tags", 11=>"Azure Provisioning", 5=>"EC2 Provisioning_old", 2=>"EC2 Provisioning_temp", 12=>"EC2 Provisioning"}, :service_type=>"atomic", :src_vm_nics=>[], :src_vm_lans=>[], :src_ems_id=>[2, "AWS"], :requester_group=>"EvmGroup-super_administrator", :pass=>0, :miq_force_unique_name=>[true, 1], :service_guid=>"76976542-03e5-45aa-a7e9-b4ad00e458c0", :service_resource_id=>1516, :owner_group=>"EvmGroup-super_administrator", :dns_domain=>nil, :vm_target_name=>"Ubuntu747", :vm_target_hostname=>"Ubuntu", :dialog_number_of_vms=>1, :dialog_vm_name=>"Ubuntu", :dialog_src_vm_id=>"933", :dialog_instance_type=>"185", :dialog_cloud_network=>"11", :dialog_placement_availability_zone=>"2", :dialog_guest_access_key_pair=>"118", :dialog_security_groups=>"167", :dialog_cloud_subnet=>"13", :run_ansible_tower_job=>0, :dialog_run_ansible_tower_job=>0, :ansible_tower_provider=>28, :dialog_ansible_tower_provider=>28, :job_template_id=>["118"], :dialog_job_template_id=>["118"], :job_credentials=>3, :dialog_job_credentials=>3, :param_ansible_ssh_user=>"ec2-user", :dialog_param_ansible_ssh_user=>"ec2-user", :sg_create_new=>0, :dialog_sg_create_new=>0, :sg_ssh_cidr=>"0.0.0.0/0", :dialog_sg_ssh_cidr=>"0.0.0.0/0", :create_sg_rules=>0, :dialog_create_sg_rules=>0, :executed_on_servers=>[5]}, created_on: "2022-07-12 08:20:15", updated_on: "2022-07-12 08:21:14", message: "State Machine Initializing", status: "Ok", type: "ManageIQ::Providers::Amazon::CloudManager::Provisi...", miq_request_id: 833, source_id: 933, source_type: "VmOrTemplate", destination_id: nil, destination_type: nil, miq_request_task_id: 2126, phase: nil, phase_context: {}, tenant_id: 1, cancelation_status: nil, conversion_host_id: nil>>
[----] E, [2022-07-12T08:21:17.248096 #305:2ad7146376b0] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) MiqAeServiceModelBase.ar_method raised: <MiqException::MiqProvisionError>: <Provision workflow does not contain the expected method <allowed_cloud_tenants>>
[----] E, [2022-07-12T08:21:17.248240 #305:2ad7146376b0] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) /var/www/miq/vmdb/app/models/mixins/miq_provision_mixin.rb:78:in `block in eligible_resources'
[----] E, [2022-07-12T08:21:17.248888 #305:2ad7146376b0] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) MiqAeServiceModelBase.ar_method raised: <MiqException::MiqProvisionError>: <Provision workflow does not contain the expected method <allowed_cloud_tenants>>
[----] E, [2022-07-12T08:21:17.249040 #305:2ad7146376b0] ERROR -- automation: Q-task_id([r833_miq_provision_2127]) /var/www/miq/vmdb/app/models/mixins/miq_provision_mixin.rb:78:in `block in eligible_resources'
[----] I, [2022-07-12T08:21:17.251053 #305:2ad7144efec4]  INFO -- automation: Q-task_id([r833_miq_provision_2127]) <AEMethod object_walker> object_walker#86314DDC:[2] !!! MiqAeServiceManageIQ_Providers_Amazon_CloudManager_Provision association 'eligible_cloud_tenants' throws a DRb::DRbRemoteError exception when accessed (product bug?) !!!

[Fryguy]

@agrare Can you take a look at this one? If it's an amazon bug, we can transfer this issue to that repo.

[agrare]

Interesting so the issue is here: https://github.com/ManageIQ/manageiq-providers-amazon/blob/bfa31d559f81/app/models/manageiq/providers/amazon/cloud_manager/provision_workflow.rb#L63 selected_group_ids = @values[:security_groups].to_a.compact It appears that @values[:security_groups] is "167" when the datatype is https://github.com/ManageIQ/manageiq/blob/master/product/dialogs/miq_dialogs/miq_provision_amazon_dialogs_template.yaml#L180

@kTipSSIoYv was this created with the UI or did you initiate this provision request with automate?

[kTipSSIoYv]

@agrare I do have a security_group ruby method for dynamic dialog and another one for creating aws security group using ruby sdk which I've written and it gets invoked. I'm not sure which one is causing the issue.

[agrare]

@kTipSSIoYv yes I believe that is causing this issue, try passing the ID in in an array like [id]

[miq-bot]

This issue has been automatically marked as stale because it has not been updated for at least 3 months.

If you can still reproduce this issue on the current release or on master, please reply with all of the information you have about it in order to keep the issue open.

Thank you for all your contributions! More information about the ManageIQ triage process can be found in the triage process documentation.

[miq-bot]

This issue has been automatically closed because it has not been updated for at least 3 months.

Feel free to reopen this issue if this issue is still valid.

Thank you for all your contributions! More information about the ManageIQ triage process can be found in the triage process documentation.