Description of problem: Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1.Tried provisioning for Amazon and RHEV . 2. requests failed . 3. Automation and EVm log are attached Actual results: Expected results: Additional info: Automation logs =================== [----] I, [2016-04-28T18:40:00.515743 #12606:11f5620] INFO -- : Q-task_id([service_template_provision_task_14]) <AEMethod provision> vmdb_object_type: service_template_provision_task [----] I, [2016-04-28T18:40:00.516769 #12606:10f1f44] INFO -- : Q-task_id([service_template_provision_task_14]) <AEMethod provision> =========================================== [----] E, [2016-04-28T18:40:00.520977 #12606:10f1f44] ERROR -- : Q-task_id([service_template_provision_task_14]) The following error occurred during instance method <execute_queue> for AR object <#<ServiceTemplateProvisionTask id: 14, description: "Provisioning [rhev_item] for Service [rhev_item]", state: "active", request_type: "clone_to_service", userid: "admin", options: {:dialog=>{"dialog_name"=>"t", "request"=>"clone_to_service"}, :workflow_settings=>{:resource_action_id=>118, :dialog_id=>3}, :src_id=>5, :requester_group=>"EvmGroup-super_administrator", :delivered_on=>2016-04-28 22:39:22 UTC, :pass=>0}, created_on: "2016-04-28 22:39:23", updated_on: "2016-04-28 22:39:59", message: "Creating Service", status: "Ok", type: "ServiceTemplateProvisionTask", miq_request_id: 12, source_id: 5, source_type: "ServiceTemplate", destination_id: 6, destination_type: "Service", miq_request_task_id: nil, phase: nil, phase_context: {}, tenant_id: 1>> [----] E, [2016-04-28T18:40:00.521231 #12606:10f1f44] ERROR -- : Q-task_id([service_template_provision_task_14]) MiqAeServiceModelBase.ar_method raised: <RuntimeError>: <Service_Template_Provisioning request is already being processed> [----] E, [2016-04-28T18:40:00.521381 #12606:10f1f44] ERROR -- : Q-task_id([service_template_provision_task_14]) /var/www/miq/vmdb/app/models/miq_request_task.rb:112:in `task_check_on_execute' /var/www/miq/vmdb/app/models/miq_request_task.rb:152:in `execute_queue' /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:263:in `block in object_send' /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:282:in `ar_method' /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:292:in `ar_method' /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:261:in `object_send' /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:122:in `block (2 levels) in expose' /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1624:in `perform_without_block' /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1584:in `perform' /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1657:in `block (2 levels) in main_loop' /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `loop' /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `block in main_loop' [----] E, [2016-04-28T18:40:00.524053 #12606:11f5620] ERROR -- : Q-task_id([service_template_provision_task_14]) <AEMethod provision> The following error occurred during method evaluation: [----] E, [2016-04-28T18:40:00.524752 #12606:11f5620] ERROR -- : Q-task_id([service_template_provision_task_14]) <AEMethod provision> RuntimeError: Service_Template_Provisioning request is already being processed [----] E, [2016-04-28T18:40:00.526056 #12606:11f5620] ERROR -- : Q-task_id([service_template_provision_task_14]) <AEMethod provision> (druby://127.0.0.1:44127) /var/www/miq/vmdb/app/models/miq_request_task.rb:112:in `task_check_on_execute' (druby://127.0.0.1:44127) /var/www/miq/vmdb/app/models/miq_request_task.rb:152:in `execute_queue' (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:263:in `block in object_send' (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:282:in `ar_method' (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:292:in `ar_method' (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:261:in `object_send' (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:122:in `block (2 levels) in expose' (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1624:in `perform_without_block' (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1584:in `perform' (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1657:in `block (2 levels) in main_loop' (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `loop' (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `block in main_loop' [----] E, [2016-04-28T18:40:00.540654 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: (druby://127.0.0.1:44127) /var/www/miq/vmdb/app/models/miq_request_task.rb:112:in `task_check_on_execute': Service_Template_Provisioning request is already being processed (RuntimeError) [----] E, [2016-04-28T18:40:00.540816 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /var/www/miq/vmdb/app/models/miq_request_task.rb:152:in `execute_queue' [----] E, [2016-04-28T18:40:00.540943 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:263:in `block in object_send' [----] E, [2016-04-28T18:40:00.541069 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:282:in `ar_method' [----] E, [2016-04-28T18:40:00.541231 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:292:in `ar_method' [----] E, [2016-04-28T18:40:00.541369 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:261:in `object_send' [----] E, [2016-04-28T18:40:00.541503 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /var/www/miq/vmdb/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:122:in `block (2 levels) in expose' [----] E, [2016-04-28T18:40:00.541621 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1624:in `perform_without_block' [----] E, [2016-04-28T18:40:00.541754 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1584:in `perform' [----] E, [2016-04-28T18:40:00.541869 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1657:in `block (2 levels) in main_loop' [----] E, [2016-04-28T18:40:00.541990 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `loop' [----] E, [2016-04-28T18:40:00.542138 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from (druby://127.0.0.1:44127) /opt/rh/rh-ruby22/root/usr/share/ruby/drb/drb.rb:1653:in `block in main_loop' [----] E, [2016-04-28T18:40:00.542278 #12606:10e7828] ERROR -- : Q-task_id([service_template_provision_task_14]) Method STDERR: from <code: $evm.root["service_template_provision_task"].execute>:9:in `<main>' [----] I, [2016-04-28T18:40:00.574526 #12594:1105990] INFO -- : MiqAeEvent.build_evm_event >> event=<:assigned_company_tag> inputs=<{"MiqEvent::miq_event"=>11306, :miq_event_id=>11306, "EventStream::event_stream"=>11306, :event_stream_id=>11306}> [----] I, [2016-04-28T18:40:00.578332 #12606:1105990] INFO -- : Q-task_id([service_template_provision_task_14]) <AEMethod [/ManageIQ/Service/Provisioning/StateMachines/Methods/provision]> Ending [----] E, [2016-04-28T18:40:00.578792 #12606:1105990] ERROR -- : Q-task_id([service_template_provision_task_14]) Aborting instantiation (unknown method return code) because [Method exited with rc=Unknown RC: [1]] [----] E, [2016-04-28T18:40:00.579063 #12606:1105990] ERROR -- : Q-task_id([service_template_provision_task_14]) State=<provision> running raised exception: <Method exited with rc=Unknown RC: [1]> [----] W, [2016-04-28T18:40:00.579315 #12606:1105990] WARN -- : Q-task_id([service_template_provision_task_14]) Error in State=[provision] [----] I, [2016-04-28T18:40:00.579544 #12606:1105990] INFO -- : Q-task_id([service_template_provision_task_14]) In State=[provision], invoking [on_error] method=[update_serviceprovision_status(status => 'Error Creating Service')] [----] I, [2016-04-28T18:40:00.584073 #12606:1105990] INFO -- : Q-task_id([service_template_provision_task_14]) Updated namespace [Service/Provisioning/StateMachines/ServiceProvision_Template/update_serviceprovision_status ManageIQ/Service/Provisioning/StateMachines] [----] I, [2016-04-28T18:40:00.584475 #12606:1105990] INFO -- : Q-task_id([service_template_provision_task_14]) Invoking [inline] method [/ManageIQ/Service/Provisioning/StateMachines/ServiceProvision_Template/update_serviceprovision_status] with inputs [{"status"=>"Error Creating Service"}] [----] I, [2016-04-28T18:40:00.585781 #12606:1105990] INFO -- : Q-task_id([service_template_provision_task_14]) <AEMethod [/ManageIQ/Service/Provisioning/StateMachines/ServiceProvision_Template/update_serviceprovision_status]> Starting [----] I, [2016-04-28T18:40:00.866496 #12594:1105990] INFO -- : MiqAeEvent.build_evm_event >> event=<:assigned_company_tag> inputs=<{"MiqEvent::miq_event"=>11307, :miq_event_id=>11307, "EventStream::event_stream"=>11307, :event_stream_id=>11307}> [----] I, [2016-04-28T18:40:01.099304 #12594:1105990] INFO -- : MiqAeEvent.build_evm_event >> event=<:assigned_company_tag> inputs=<{"MiqEvent::miq_event"=>11308, :miq_event_id=>11308, "EventStream::event_stream"=>11308, :event_stream_id=>11308}> [----] I, [2016-04-28T18:40:01.241213 #12594:1105990] INFO -- : MiqAeEvent.build_evm_event >> event=<:assigned_company_tag> inputs=<{"MiqEvent::miq_event"=>11309, :miq_event_id=>11309, "EventStream::event_stream"=>11309, :event_stream_id=>11309}> [----] I, [2016-04-28T18:40:01.320262 #12606:1105990] INFO -- : Q-task_id([service_template_provision_task_14]) <AEMethod [/ManageIQ/Service/Provisioning/StateMachines/ServiceProvision_Template/update_serviceprovision_status]> Ending [----
Created attachment 1152072 [details] logs
*** This bug has been marked as a duplicate of bug 1330190 ***