Bug 1666834

Summary: Retirement Service Retire Task State Validation error in evm.log
Product: Red Hat CloudForms Management Engine Reporter: Tina Fitzgerald <tfitzger>
Component: AutomateAssignee: Tina Fitzgerald <tfitzger>
Status: CLOSED CURRENTRELEASE QA Contact: Niyaz Akhtar Ansari <nansari>
Severity: medium Docs Contact: Red Hat CloudForms Documentation <cloudforms-docs>
Priority: high    
Version: 5.10.0CC: dmetzger, duhlmann, mkanoor, obarenbo, rchincho, simaishi, sshveta, tfitzger
Target Milestone: GAKeywords: Regression, TestOnly, ZStream
Target Release: 5.11.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: 5.11.0.1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1672700 (view as bug list) Environment:
Last Closed: 2019-12-13 15:16:14 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: CFME Core Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1672700    

Description Tina Fitzgerald 2019-01-16 17:09:31 UTC
Description of problem:
Validation error shown in evm.log while doing Service retirement.

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

How reproducible:
Retire a Service

Steps to Reproduce:
1. Provision  a Service Item.
2. Retire the Service item.
3. Check the evm.log for validation error.

Actual results:
evm.log log errors:

****
[----] I, [2019-01-15T12:51:35.081095 #15205:7b7a2bc]  INFO -- : Finishing Retirement for [tpci-20190115-123511]
[----] I, [2019-01-15T12:51:35.088429 #15205:7b7a2bc]  INFO -- : Calling audit event for: Service: [tpci-20190115-123511], Retires On: [01/15/19 17:51 UTC], has been retired 
[----] I, [2019-01-15T12:51:35.109574 #15205:7b7a2bc]  INFO -- : <AuditSuccess> MIQ(RetirementMixin.raise_audit_event) userid: [system] - Service: [tpci-20190115-123511], Retires On: [01/15/19 17:51 UTC], has be
en retired
[----] I, [2019-01-15T12:51:35.109617 #15205:7b7a2bc]  INFO -- : Called audit event for: Service: [tpci-20190115-123511], Retires On: [01/15/19 17:51 UTC], has been retired 
[----] I, [2019-01-15T12:51:36.760549 #15205:496f60]  INFO -- : Q-task_id([r2_service_retire_task_4]) MIQ(ServiceRetireTask#after_ae_delivery) ae_result="ok"
[----] I, [2019-01-15T12:51:36.777060 #15205:496f60]  INFO -- : Q-task_id([r2_service_retire_task_4]) Child tasks finished but current task still processing. Setting state to: [retired]...
[----] E, [2019-01-15T12:51:36.781404 #15205:496f60] ERROR -- : Q-task_id([r2_service_retire_task_4]) MIQ(MiqQueue#deliver) Message id: [449], Error: [Validation failed: ServiceRetireTask: State should be pending, finished, active, queued]
[----] E, [2019-01-15T12:51:36.781593 #15205:496f60] ERROR -- : Q-task_id([r2_service_retire_task_4]) [ActiveRecord::RecordInvalid]: Validation failed: ServiceRetireTask: State should be pending, finished, active, queued  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2019-01-15T12:51:36.781665 #15205:496f60] ERROR -- : Q-task_id([r2_service_retire_task_4]) /opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/validations.rb:78:in `raise_validation_error'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/validations.rb:50:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/attribute_methods/dirty.rb:30:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/transactions.rb:324:in `block in save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/suppressor.rb:45:in `save!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/persistence.rb:288:in `block in update!'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/transactions.rb:395:in `block in with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `block in transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/connection_adapters/abstract/transaction.rb:189:in `within_new_transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/transactions.rb:211:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/transactions.rb:392:in `with_transaction_returning_status'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.1/lib/active_record/persistence.rb:286:in `update!'
/var/www/miq/vmdb/app/models/miq_request_task.rb:50:in `update_and_notify_parent'
/var/www/miq/vmdb/app/models/service_retire_task.rb:14:in `update_and_notify_parent'
/var/www/miq/vmdb/app/models/miq_request_task.rb:94:in `update_request_status'
/var/www/miq/vmdb/app/models/miq_request_task.rb:55:in `update_and_notify_parent'
/var/www/miq/vmdb/app/models/service_retire_task.rb:14:in `update_and_notify_parent'
/var/www/miq/vmdb/app/models/miq_retire_task.rb:66:in `after_ae_delivery'
/opt/rh/cfme-gemset/bundler/gems/cfme-automation_engine-9ad88a1d9cc9/lib/miq_automation_engine/engine/miq_ae_engine.rb:130:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue.rb:455:in `block in dispatch_method'
[...]
[----] I, [2019-01-15T12:51:36.781843 #15205:496f60]  INFO -- : Q-task_id([r2_service_retire_task_4]) MIQ(MiqQueue#delivered) Message id: [449], State: [error], Delivered in [13.348539546] seconds
****


Expected results:
No evm.log errors.

Additional info:

Comment 3 Niyaz Akhtar Ansari 2019-02-04 18:02:27 UTC
It was working on earlier build 5.9.7.Adding Regression keyword

Comment 7 drew uhlmann 2019-04-09 14:55:18 UTC
We believe that this is in fact the same issue, Rahul. As a note, 5.10.0 is pretty old, and we also believe this has been fixed. Please reopen a new ticket if you run into this again on a newer version. Thanks!

Comment 8 Niyaz Akhtar Ansari 2019-05-14 17:31:10 UTC
Verified in Version: 5.11.0.3.20190507174347_a77bd90