Created attachment 1096796 [details] Automate and EVM logs Description of problem: NoMethodError: undefined method `message=' for nil:NilClass ===snippet=== [----] I, [2015-11-19T11:18:13.690168 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) Invoking [inline] method [/ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status] with inputs [{"status"=>"Customizing Request"}] [----] I, [2015-11-19T11:18:13.690964 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod [/ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status]> Starting [----] E, [2015-11-19T11:18:14.211418 #14067:4d94f3c] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod update_provision_status> The following error occurred during method evaluation: [----] E, [2015-11-19T11:18:14.212407 #14067:4d94f3c] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod update_provision_status> NoMethodError: undefined method `message=' for nil:NilClass [----] E, [2015-11-19T11:18:14.213789 #14067:4d94f3c] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod update_provision_status> [----] E, [2015-11-19T11:18:14.216154 #14067:4d951d0] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) Method STDERR: <code: prov.message = status>:11:in `<main>': undefined method `message=' for nil:NilClass (NoMethodError) [----] I, [2015-11-19T11:18:14.230778 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod [/ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status]> Ending [----] E, [2015-11-19T11:18:14.231230 #14067:b31988] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) State=<CustomizeRequest> running on_entry raised exception: <Method exited with rc=Unknown RC: [1]> [----] W, [2015-11-19T11:18:14.231404 #14067:b31988] WARN -- : Q-task_id([service_template_provision_task_10000000000013]) Error in State=[CustomizeRequest] [----] I, [2015-11-19T11:18:14.231586 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) In State=[CustomizeRequest], invoking [on_error] method=[update_provision_status(status => 'Error Customizing Request')] [----] I, [2015-11-19T11:18:14.236165 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) Updated namespace [Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status ManageIQ/Infrastructure/VM/Provisioning/StateMachines] [----] I, [2015-11-19T11:18:14.236582 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) Invoking [inline] method [/ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status] with inputs [{"status"=>"Error Customizing Request"}] [----] I, [2015-11-19T11:18:14.237318 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod [/ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status]> Starting [----] E, [2015-11-19T11:18:14.756259 #14067:4d361e4] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod update_provision_status> The following error occurred during method evaluation: [----] E, [2015-11-19T11:18:14.757176 #14067:4d361e4] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod update_provision_status> NoMethodError: undefined method `message=' for nil:NilClass [----] E, [2015-11-19T11:18:14.758651 #14067:4d361e4] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod update_provision_status> [----] E, [2015-11-19T11:18:14.761212 #14067:4d36964] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) Method STDERR: <code: prov.message = status>:11:in `<main>': undefined method `message=' for nil:NilClass (NoMethodError) [----] I, [2015-11-19T11:18:14.775529 #14067:b31988] INFO -- : Q-task_id([service_template_provision_task_10000000000013]) <AEMethod [/ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status]> Ending [----] E, [2015-11-19T11:18:14.775888 #14067:b31988] ERROR -- : Q-task_id([service_template_provision_task_10000000000013]) State=<CustomizeRequest> running on_error raised exception: <Method exited with rc=Unknown RC: [1]> ==snippet end == Version-Release number of selected component (if applicable): 5.5.0.11-rc1.20151117182049_653c0d4 How reproducible: every time Steps to Reproduce: As admin 1. Create a service catalog item pointing to a vmware template that provisions fine from lifecycle -> provision 2. Create catalog item with the same values as used in step to provision via lifecycle - provision 3. Provision the service catalog item Actual results: throws error Expected results: provision the same as the same template with same choices via lifecycle -> provision Additional info: automate logs attached, times of interest: around 2015-11-19T11:11 you will see standard lifecycle provision working correctly around 2015-11-19T11:17:52 you will see service provision of same with error from ordering via service catalog in classic UI around 2015-11-19T11:20 you will see service provision of same with error from ordering via service catalog in self service UI
Reopening this issue because we should not have seen a stack trace. The method should have failed cleanly with a proper message. The issue happens because the service provisioning points to a VM state machine. There is a bug in the Automate Method /ManageIQ/Cloud/VM/Provisioning/StateMachines/VMProvision_VM/update_provision_status /ManageIQ/Infrastructure/Configured_System/Provisioning/StateMachines/Provision/ update_provision_status /ManageIQ/Service/Provisioning/StateMachines/ServiceProvision_Template/ update_serviceprovision_status /ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_VM/ update_provision_status /ManageIQ/Infrastructure/VM/Provisioning/StateMachines/VMProvision_Template/ update_provision_status /ManageIQ/Infrastructure/Host/Provisioning/StateMachines/HostProvision/ update_provision_status We are not checking if the provision object is valid. This causes the stack trace to be generated.
/ManageIQ/Cloud/Orchestration/Provisioning/StateMachines/Provision/update_serviceprovision_status is also one of the methods
https://github.com/ManageIQ/manageiq/pull/5608
New commit detected on ManageIQ/manageiq/master: https://github.com/ManageIQ/manageiq/commit/c50201da980791d1c3de7cb4025385f7f8e65c53 commit c50201da980791d1c3de7cb4025385f7f8e65c53 Author: Madhu Kanoor <mkanoor> AuthorDate: Wed Nov 25 16:24:03 2015 -0500 Commit: Madhu Kanoor <mkanoor> CommitDate: Wed Nov 25 16:24:03 2015 -0500 Fixed Automate methods https://bugzilla.redhat.com/show_bug.cgi?id=1283724 Fixed Automate methods to check if there is a valid provision object. Added specs .../__methods__/update_serviceprovision_status.rb | 5 +++ .../__methods__/update_provision_status.rb | 4 +++ .../__methods__/update_provision_status.rb | 5 +++ .../__methods__/update_provision_status.rb | 5 +++ .../__methods__/update_provision_status.rb | 5 +++ .../__methods__/update_provision_status.rb | 5 +++ .../update_provision_status_vm_cloud_spec.rb | 40 +++++++++++++++++++++ .../update_provision_status_vm_infra_spec.rb | 41 ++++++++++++++++++++++ ...date_provision_status_vm_template_infra_spec.rb | 41 ++++++++++++++++++++++ ..._service_provision_status_orchestration_spec.rb | 33 +++++++++++++++++ spec/support/automation_spec_helper.rb | 12 +++++++ 11 files changed, 196 insertions(+) create mode 100644 spec/automation/unit/method_validation/update_provision_status_vm_cloud_spec.rb create mode 100644 spec/automation/unit/method_validation/update_provision_status_vm_infra_spec.rb create mode 100644 spec/automation/unit/method_validation/update_provision_status_vm_template_infra_spec.rb create mode 100644 spec/automation/unit/method_validation/update_service_provision_status_orchestration_spec.rb
https://github.com/ManageIQ/manageiq/pull/6577
Fixed. verified in 5.6.0.1-beta2.20160413141124_e25ac0e
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