Bug 1330190 - Service provisioning fails with "Service_Template_Provisioning request is already being processed"
Summary: Service provisioning fails with "Service_Template_Provisioning request is alr...
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: Beta 2
: 5.6.0
Assignee: Bill Wei
QA Contact: Shveta
URL:
Whiteboard: service:provision
: 1331594 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-04-25 14:55 UTC by Greg McCullough
Modified: 2016-06-29 15:54 UTC (History)
5 users (show)

Fixed In Version: 5.6.0.6
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-06-29 15:54:17 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 Greg McCullough 2016-04-25 14:55:45 UTC
Description of problem: Service provisioning fails in Service/Provisioning/StateMachines/Methods/provision with "MiqAeServiceModelBase.ar_method raised: <RuntimeError>: <Service_Template_Provisioning request is already being processed>
"

Version-Release number of selected component (if applicable): 5.6


How reproducible: Always


Steps to Reproduce:
1. Create a generic service (Use default values and any dialog)
2. Order service

Actual results:
Service provisioning fails

Expected results:
Service provisioning is successful


Additional info:
E, [2016-04-24T10:21:41.671273 #28855:3fcc32013694] ERROR -- : The following error occurred during instance method <execute_queue> for AR object <#<ServiceTemplateProvisionTask id: 757, description: "Provisioning [generic_svc_1] for Service [generic_...", state: "active", request_type: "clone_to_service", userid: "admin", options: {:dialog=>{"dialog_asdf"=>"1234", "dialog_buttons"=>"on", "dialog_text2"=>"1", "request"=>"clone_to_service"}, :workflow_settings=>{:resource_action_id=>44, :dialog_id=>83}, :src_id=>33, :requester_group=>"EvmGroup-super_administrator", :delivered_on=>2016-04-24 14:21:31 UTC, :pass=>0}, created_on: "2016-04-24 14:21:31", updated_on: "2016-04-24 14:21:40", message: "Creating Service", status: "Ok", type: "ServiceTemplateProvisionTask", miq_request_id: 893, source_id: 33, source_type: "ServiceTemplate", destination_id: 328, destination_type: "Service", miq_request_task_id: nil, phase: nil, phase_context: {}, tenant_id: 1>>
[----] E, [2016-04-24T10:21:41.671394 #28855:3fcc32013694] ERROR -- : MiqAeServiceModelBase.ar_method raised: <RuntimeError>: <Service_Template_Provisioning request is already being processed>
[----] E, [2016-04-24T10:21:41.671435 #28855:3fcc32013694] ERROR -- : /Users/gmccullough/work/manageiq/app/models/miq_request_task.rb:112:in `task_check_on_execute'
/Users/gmccullough/work/manageiq/app/models/miq_request_task.rb:152:in `execute_queue'
/Users/gmccullough/work/manageiq/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:263:in `block in object_send'
/Users/gmccullough/work/manageiq/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:282:in `ar_method'
/Users/gmccullough/work/manageiq/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:292:in `ar_method'
/Users/gmccullough/work/manageiq/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:261:in `object_send'
/Users/gmccullough/work/manageiq/lib/miq_automation_engine/engine/miq_ae_service_model_base.rb:122:in `block (2 levels) in expose'
/Users/g

Comment 3 CFME Bot 2016-04-26 19:11:07 UTC
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/456e3de51f9511c7f7de2e0674a539cafb7e5f81

commit 456e3de51f9511c7f7de2e0674a539cafb7e5f81
Author:     Bill Wei <bilwei>
AuthorDate: Tue Apr 26 09:03:18 2016 -0400
Commit:     Bill Wei <bilwei>
CommitDate: Tue Apr 26 12:37:29 2016 -0400

    Allow the task state to be active when executing the queue
    
    The state is still forbidden being active when delivering to automate
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1330190

 app/models/miq_request_task.rb                     |  8 ++-
 app/models/service_template_provision_task.rb      |  2 +-
 .../models/service_template_provision_task_spec.rb | 80 ++++++++++++++++------
 3 files changed, 65 insertions(+), 25 deletions(-)

Comment 4 Greg McCullough 2016-04-29 13:27:01 UTC
*** Bug 1331594 has been marked as a duplicate of this bug. ***

Comment 5 Shveta 2016-05-04 22:10:35 UTC
I am not seeing any error in logs but request is taking too long to provision , it times out the maximum number of retries and then fails.

Can be checked at https://10.16.5.86

Comment 6 Greg McCullough 2016-05-05 19:09:30 UTC
While debugging the issue with Tina/Bill we discovered the issue is still related to the changes from PR https://github.com/ManageIQ/manageiq/pull/7914.

In this case the state of a task was being reverted from "provisioned" to "active" and would never complete the check_provisioned state of the service provisioning state-machine.

Comment 8 CFME Bot 2016-05-05 23:20:41 UTC
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/9eeb43fc6115de91b60c4d03f66a0ee43c06e13d

commit 9eeb43fc6115de91b60c4d03f66a0ee43c06e13d
Author:     Bill Wei <bilwei>
AuthorDate: Thu May 5 15:28:14 2016 -0400
Commit:     Bill Wei <bilwei>
CommitDate: Thu May 5 17:56:59 2016 -0400

    only allow state changing from pending or queued to active
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1330190

 app/models/service_template_provision_task.rb      |  2 +-
 .../models/service_template_provision_task_spec.rb | 28 +++++++++++++++++-----
 2 files changed, 23 insertions(+), 7 deletions(-)

Comment 9 Shveta 2016-05-12 22:53:50 UTC
Verified in 5.6.0.6-beta2.5.20160511140943_ff75fb2

Comment 12 errata-xmlrpc 2016-06-29 15:54:17 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.