Bug 1839770

Summary: Retirement of a vm from central region fails with "invalid system authentication token specified"
Product: Red Hat CloudForms Management Engine Reporter: Felix Dewaleyne <fdewaley>
Component: ApplianceAssignee: Yuri Rudman <yrudman>
Status: CLOSED ERRATA QA Contact: Tasos Papaioannou <tpapaioa>
Severity: medium Docs Contact: Red Hat CloudForms Documentation <cloudforms-docs>
Priority: high    
Version: 5.11.5CC: dmetzger, fdewaley, obarenbo, sigbjorn.lie, simaishi, tpapaioa, yrudman
Target Milestone: GAKeywords: ZStream
Target Release: 5.11.7Flags: simaishi: cfme-5.11.z+
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: 5.11.7.0 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-08-06 14:32:54 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:

Description Felix Dewaleyne 2020-05-25 13:49:05 UTC 
Description of problem:
When initiating a retirement of a vm from the central region (vm_retire_now), an error "invalid system authentication token specified" is raised, but service_retire_now passes with no issue

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

How reproducible:
all the time in customer setup

Steps to Reproduce:
1.set up 2 or more regions with one being central
2.set up providers and service provisioinng vms
3.retire from the central region a vm

Actual results:
[----] I, [2020-05-25T13:22:52.227416 #2556:2ab7d0e5c5c4]  INFO -- : MIQ(ManageIQ::Providers::Redhat::InfraManager::Vm.set_retirement_requester) Retirement requester for ManageIQ::Providers::Redhat::InfraManager::Vm [2000000000080] being set to someone
[----] E, [2020-05-25T13:22:52.986580 #2556:2ab7d0e5c5c4] ERROR -- : MIQ(MiqQueue#m_callback) Message id: [99000002248872]: Invalid System Authentication Token specified
[----] E, [2020-05-25T13:22:52.987006 #2556:2ab7d0e5c5c4] ERROR -- : [RuntimeError]: Invalid System Authentication Token specified  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2020-05-25T13:22:52.987260 #2556:2ab7d0e5c5c4] ERROR -- : /opt/rh/cfme-gemset/gems/manageiq-api-client-0.3.3/lib/manageiq/api/client/connection.rb:111:in `check_response'
/opt/rh/cfme-gemset/gems/manageiq-api-client-0.3.3/lib/manageiq/api/client/connection.rb:102:in `send_request'
/opt/rh/cfme-gemset/gems/manageiq-api-client-0.3.3/lib/manageiq/api/client/connection.rb:24:in `get'
/opt/rh/cfme-gemset/gems/manageiq-api-client-0.3.3/lib/manageiq/api/client/client.rb:37:in `load_definitions'
/opt/rh/cfme-gemset/gems/manageiq-api-client-0.3.3/lib/manageiq/api/client/client.rb:62:in `reconnect'
/opt/rh/cfme-gemset/gems/manageiq-api-client-0.3.3/lib/manageiq/api/client/client.rb:33:in `initialize'
/var/www/miq/vmdb/app/models/mixins/inter_region_api_method_relay.rb:65:in `new'


Expected results:
the vm retirement passes

Additional info:
looking into this I did find https://bugzilla.redhat.com/show_bug.cgi?id=1750440 and a couple other bugs and am investigating differences in external authentication settings and roles between the regions in use by the customer.
Comment 2 Felix Dewaleyne 2020-05-29 12:07:46 UTC 
There seem to be issues with the api on the destination region : 

[----] I, [2020-05-28T14:51:28.921664 #5367:2ad7599275c4]  INFO -- : MIQ(Api::ApiController.log_request_initiated)  
[----] I, [2020-05-28T14:51:28.921938 #5367:2ad7599275c4]  INFO -- : MIQ(Api::ApiController.log_request) API Request:    {:requested_at=>"2020-05-28 12:51:28 UTC", :method=>"GET", :url=>"https://10.11.12.13/api?attributes=authorization"}
[----] E, [2020-05-28T14:51:28.929711 #5367:2ad7599275c4] ERROR -- : MIQ(Api::ApiController.rescue in authenticate_with_system_token) Authentication Failed with System Token
X-MIQ-Token: v2:{URXb7g5cpwP5fzGAY8U1rRozucGWZ2vpIMfk1dj5jx3rch749Kttmlnq2uRmY/Xs0TKhXvUQvX8lIKKecNdHGsEillUBb4Ky8XYFPJhO07Ke07hEs2xkXy4QnAqQZUAgbWrzN6mW06GY/6Sqxt0euA==}
Error: undefined method `downcase' for nil:NilClass
[----] E, [2020-05-28T14:51:28.929843 #5367:2ad7599275c4] ERROR -- : MIQ(Api::ApiController.rescue in require_api_user_or_token) AuthenticationError: Invalid System Authentication Token specified
[----] I, [2020-05-28T14:51:28.932365 #5367:2ad7599275c4]  INFO -- : MIQ(Api::ApiController.log_request) Response:       {:completed_at=>"2020-05-28 12:51:28 UTC", :size=>"0.126 KBytes", :time_taken=>"0.011 Seconds", :status=>401}
[----] I, [2020-05-28T14:52:58.912818 #5367:2ad75991e848]  INFO -- : MIQ(Api::ApiController.log_request_initiated)  
[----] I, [2020-05-28T14:52:58.913729 #5367:2ad75991e848]  INFO -- : MIQ(Api::ApiController.log_request) API Request:    {:requested_at=>"2020-05-28 12:52:58 UTC", :method=>"GET", :url=>"https://10.11.12.13/api?attributes=authorization"}
[----] E, [2020-05-28T14:52:58.918027 #5367:2ad75991e848] ERROR -- : MIQ(Api::ApiController.rescue in authenticate_with_system_token) Authentication Failed with System Token
X-MIQ-Token: v2:{URXb7g5cpwP5fzGAY8U1rRozucGWZ2vpIMfk1dj5jx3rch749Kttmlnq2uRmY/Xs0TKhXvUQvX8lIKKecNdHGsEillUBb4Ky8XYFPJhO07Lm9MGZltHFCRt0TrHXI6M8Xqbq2v5X24HVMTCaueym3w==}
Error: undefined method `downcase' for nil:NilClass
[----] E, [2020-05-28T14:52:58.918142 #5367:2ad75991e848] ERROR -- : MIQ(Api::ApiController.rescue in require_api_user_or_token) AuthenticationError: Invalid System Authentication Token specified
[----] I, [2020-05-28T14:52:58.918486 #5367:2ad75991e848]  INFO -- : MIQ(Api::ApiController.log_request) Response:       {:completed_at=>"2020-05-28 12:52:58 UTC", :size=>"0.126 KBytes", :time_taken=>"0.006 Seconds", :status=>401}
[----] I, [2020-05-28T14:54:14.852234 #5375:2ad7598dfae4]  INFO -- : MIQ(Api::ApiController.log_request_initiated)  
[----] I, [2020-05-28T14:54:14.852421 #5375:2ad7598dfae4]  INFO -- : MIQ(Api::ApiController.log_request) API Request:    {:requested_at=>"2020-05-28 12:54:14 UTC", :method=>"GET", :url=>"https://10.11.12.13/api?attributes=authorization"}
[----] E, [2020-05-28T14:54:14.858405 #5375:2ad7598dfae4] ERROR -- : MIQ(Api::ApiController.rescue in authenticate_with_system_token) Authentication Failed with System Token
X-MIQ-Token: v2:{URXb7g5cpwP5fzGAY8U1rRozucGWZ2vpIMfk1dj5jx3rch749Kttmlnq2uRmY/Xs0TKhXvUQvX8lIKKecNdHGsEillUBb4Ky8XYFPJhO07ImTNANLZhZ/IR++RQPFvPe3B5yLkCxzWfqC2Iyu3tzMg==}
Error: undefined method `downcase' for nil:NilClass
[----] E, [2020-05-28T14:54:14.858519 #5375:2ad7598dfae4] ERROR -- : MIQ(Api::ApiController.rescue in require_api_user_or_token) AuthenticationError: Invalid System Authentication Token specified
[----] I, [2020-05-28T14:54:14.860603 #5375:2ad7598dfae4]  INFO -- : MIQ(Api::ApiController.log_request) Response:       {:completed_at=>"2020-05-28 12:54:14 UTC", :size=>"0.126 KBytes", :time_taken=>"0.008 Seconds", :status=>401}
[----] I, [2020-05-28T14:54:57.477066 #5383:2ad7598af150]  INFO -- : MIQ(Api::ApiController.log_request_initiated)  
[----] I, [2020-05-28T14:54:57.477235 #5383:2ad7598af150]  INFO -- : MIQ(Api::ApiController.log_request) API Request:    {:requested_at=>"2020-05-28 12:54:57 UTC", :method=>"GET", :url=>"https://10.11.12.13/api?attributes=authorization"}
[----] E, [2020-05-28T14:54:57.483563 #5383:2ad7598af150] ERROR -- : MIQ(Api::ApiController.rescue in authenticate_with_system_token) Authentication Failed with System Token
X-MIQ-Token: v2:{URXb7g5cpwP5fzGAY8U1rRozucGWZ2vpIMfk1dj5jx3rch749Kttmlnq2uRmY/Xs0TKhXvUQvX8lIKKecNdHGsEillUBb4Ky8XYFPJhO07IknrEWc4yur3IQ9DMiKF21eevL2GK/UojzPXfQvJlhFQ==}
Error: undefined method `downcase' for nil:NilClass
[----] E, [2020-05-28T14:54:57.483667 #5383:2ad7598af150] ERROR -- : MIQ(Api::ApiController.rescue in require_api_user_or_token) AuthenticationError: Invalid System Authentication Token specified
[----] I, [2020-05-28T14:54:57.485851 #5383:2ad7598af150]  INFO -- : MIQ(Api::ApiController.log_request) Response:       {:completed_at=>"2020-05-28 12:54:57 UTC", :size=>"0.126 KBytes", :time_taken=>"0.009 Seconds", :status=>401}
[----] I, [2020-05-28T15:00:46.703449 #5391:2ad7598a27e8]  INFO -- : MIQ(Api::ApiController.log_request_initiated)  
[----] I, [2020-05-28T15:00:46.703612 #5391:2ad7598a27e8]  INFO -- : MIQ(Api::ApiController.log_request) API Request:    {:requested_at=>"2020-05-28 13:00:46 UTC", :method=>"GET", :url=>"https://10.11.12.13/api?attributes=authorization"}
[----] E, [2020-05-28T15:00:46.709682 #5391:2ad7598a27e8] ERROR -- : MIQ(Api::ApiController.rescue in authenticate_with_system_token) Authentication Failed with System Token
X-MIQ-Token: v2:{URXb7g5cpwP5fzGAY8U1rRozucGWZ2vpIMfk1dj5jx3rch749Kttmlnq2uRmY/Xs0TKhXvUQvX8lIKKecNdHGsEillUBb4Ky8XYFPJhO07IaRQSMdC1Jpqk2BAn7LQwkgp1RGupxtBWD8W0WvX90+g==}
Error: undefined method `downcase' for nil:NilClass
[----] E, [2020-05-28T15:00:46.709806 #5391:2ad7598a27e8] ERROR -- : MIQ(Api::ApiController.rescue in require_api_user_or_token) AuthenticationError: Invalid System Authentication Token specified
[----] I, [2020-05-28T15:00:46.711839 #5391:2ad7598a27e8]  INFO -- : MIQ(Api::ApiController.log_request) Response:       {:completed_at=>"2020-05-28 13:00:46 UTC", :size=>"0.126 KBytes", :time_taken=>"0.008 Seconds", :status=>401}
(END)
Comment 6 CFME Bot 2020-06-03 22:20:19 UTC 
https://github.com/ManageIQ/manageiq/pull/20244
Comment 7 Yuri Rudman 2020-06-04 15:37:54 UTC 
It is bug: we did not supply requester's id when queued retirement request delivered from queue for execution,
above PR should fix it.
Comment 8 CFME Bot 2020-06-04 15:40:30 UTC 
New commit detected on ManageIQ/manageiq/master:

https://github.com/ManageIQ/manageiq/commit/a4d3dafced1eae5f872c5fa9317beebb458c808e
commit a4d3dafced1eae5f872c5fa9317beebb458c808e
Author:     Yuri Rudman <yrudman>
AuthorDate: Tue Jun  2 12:06:45 2020 +0000
Commit:     Yuri Rudman <yrudman>
CommitDate: Tue Jun  2 12:06:45 2020 +0000

    accept 'user_name' from passed arguments when iitiating InterRegion api call
    Fixes https://bugzilla.redhat.com/show_bug.cgi?id=1839770

 app/models/mixins/inter_region_api_method_relay.rb | 5 +-
 1 file changed, 4 insertions(+), 1 deletion(-)
Comment 9 Satoe Imaishi 2020-06-18 20:18:27 UTC 
commit 5fa5813476646ab3ad99f5f2e50b4d48e44fb99e
Author: Nick Carboni <ncarboni>
Date:   Thu Jun 4 11:35:27 2020 -0400

    Merge pull request #20244 from yrudman/fix-retirement-from-global

    Fix vm retirement initiated on global region

    (cherry picked from commit 97c2e5b9d7992d84d67ed65cd4c6cad07dfdabdb)
Comment 10 Tasos Papaioannou 2020-07-16 14:12:39 UTC 
Verified on 5.11.7.0.
Comment 13 errata-xmlrpc 2020-08-06 14:32:54 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 (Critical: CloudForms 5.0.7 bug fix and enhancement update), 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/RHSA-2020:3358