Bug 1331594 - Service : Provisioning requests through service catalogs fails
Summary: Service : Provisioning requests through service catalogs fails
Keywords:
Status: CLOSED DUPLICATE of bug 1330190
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Provisioning
Version: 5.6.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: GA
: 5.6.0
Assignee: Greg McCullough
QA Contact: Dave Johnson
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-04-28 22:57 UTC by Shveta
Modified: 2016-05-03 03:55 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-04-29 13:27:01 UTC
Category: ---
Cloudforms Team: ---
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
logs (12.33 MB, application/zip)
2016-04-28 23:19 UTC, Shveta
no flags Details

Description Shveta 2016-04-28 22:57:29 UTC
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
[----

Comment 2 Shveta 2016-04-28 23:19:57 UTC
Created attachment 1152072 [details]
logs

Comment 3 Greg McCullough 2016-04-29 13:27:01 UTC

*** This bug has been marked as a duplicate of bug 1330190 ***


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