This bug has been migrated to another issue tracking site. It has been closed here and may no longer be being monitored.

If you would like to get updates for this issue, or to participate in it, you may do so at Red Hat Issue Tracker .
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 2177721 - [Nutanix] virt-who always shows Source Status:success for nutanix mode
Summary: [Nutanix] virt-who always shows Source Status:success for nutanix mode
Keywords:
Status: CLOSED MIGRATED
Alias: None
Product: Red Hat Enterprise Linux 9
Classification: Red Hat
Component: virt-who
Version: 9.2
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: rc
: ---
Assignee: candlepin-bugs
QA Contact: yuefliu
URL:
Whiteboard:
Depends On:
Blocks: 2209174
TreeView+ depends on / blocked
 
Reported: 2023-03-13 13:56 UTC by yuefliu
Modified: 2023-10-10 10:57 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2023-10-10 10:57:56 UTC
Type: Bug
Target Upstream Version:
Embargoed:
pm-rhel: mirror+


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker   RHEL-12407 0 None Migrated None 2023-10-10 10:57:52 UTC
Red Hat Issue Tracker RHELPLAN-151772 0 None None None 2023-03-14 14:06:03 UTC

Description yuefliu 2023-03-13 13:56:31 UTC
Description of problem:
When configure virt-who run with bad nutanix/ahv configuration file, it will fail to get the mapping, but still show Source Status: success when run the #virt-who --status


Version-Release number of selected component (if applicable):
virt-who-1.31.26-1.el9.noarch

How reproducible:
always for nutanix

Steps to Reproduce:
1. configure bad nutanix/ahv config file
# vi /etc/virt-whod/virtwho-config.conf 
[virtwho-config]
type=ahv
server=10.73.131.xxx
username=admin
password=xxx
owner=xxx

2. Run virt-who, it will be failed to get and send mappings
# virt-who -do
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "status" not set, using default: False
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "json" not set, using default: False
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "print_" not set, using default: False
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "log_per_config" not set, using default: False
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "configs" not set, using default: []
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "reporter_id" not set, using default: hp-z220-05.qe.lab.eng.nay.redhat.com-0df187d5b26b461ea384904b34d89fd4
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "interval" not set, using default: 3600
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "log_file" not set, using default: rhsm.log
2023-03-13 09:54:02,204 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [global]: Value for "log_dir" not set, using default: /var/log/rhsm
2023-03-13 09:54:02,205 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [virtwho-config]: Value for "hypervisor_id" not set, using default: uuid
2023-03-13 09:54:02,205 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [virtwho-config]: Value for "is_hypervisor" not set, using default: True
2023-03-13 09:54:02,205 [virtwho.rhsm_log DEBUG] MainProcess(481643):MainThread @config.py:init_config:1582 - [virtwho-config]: Value for "ahv_internal_debug" not set, using default: False
2023-03-13 09:54:02,205 [virtwho.rhsm_log INFO] MainProcess(481643):MainThread @executor.py:__init__:52 - Using config named 'virtwho-config'
2023-03-13 09:54:02,205 [virtwho.rhsm_log INFO] MainProcess(481643):MainThread @main.py:main:136 - Using configuration "virtwho-config" ("ahv" mode)
2023-03-13 09:54:02,205 [virtwho.rhsm_log INFO] MainProcess(481643):MainThread @main.py:main:139 - Using reporter_id='hp-z220-05.qe.lab.eng.nay.redhat.com-0df187d5b26b461ea384904b34d89fd4'
2023-03-13 09:54:02,214 [rhsm.https DEBUG] MainProcess(481643):MainThread @https.py:<module>:57 - Using standard libs to provide httplib and ssl
2023-03-13 09:54:02,221 [virtwho.main DEBUG] MainProcess(481643):Thread-2 @virt.py:run:513 - Thread 'virtwho-config' started
2023-03-13 09:54:05,107 [virtwho.main ERROR] MainProcess(481643):Thread-2 @virt.py:run:521 - Thread 'virtwho-config' fails with error: HTTP Auth Failed get https://10.73.131.xxx:9440/api/nutanix/v2.0/hosts. 
 res: response: <Response [401]>
2023-03-13 09:54:05,108 [virtwho.main INFO] MainProcess(481643):Thread-2 @virt.py:_send_data:1191 - Report for config "virtwho-config" gathered, placing in datastore
2023-03-13 09:54:05,108 [virtwho.main DEBUG] MainProcess(481643):Thread-2 @virt.py:run:547 - Thread 'virtwho-config' stopped after running once
2023-03-13 09:54:05,226 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:__init__:239 - Environment variable NO_PROXY= will be used
2023-03-13 09:54:05,227 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:__init__:623 - Creating new BaseRestLib instance
2023-03-13 09:54:05,226 [virtwho.destination_484620994773772658 DEBUG] MainProcess(481643):Thread-3 @virt.py:run:513 - Thread 'destination_484620994773772658' started
2023-03-13 09:54:05,226 [virtwho.destination_484620994773772658 DEBUG] MainProcess(481643):Thread-3 @subscriptionmanager.py:_connect:151 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2023-03-13 09:54:05,226 [virtwho.destination_484620994773772658 INFO] MainProcess(481643):Thread-3 @subscriptionmanager.py:_connect:158 - X-Correlation-ID: f0057070a2c447bdb80af470f91aa2ca
2023-03-13 09:54:05,227 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:__init__:365 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=0
2023-03-13 09:54:05,228 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1093 - Making request: GET /subscription/status/
2023-03-13 09:54:05,230 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_create_connection:772 - Creating new connection
2023-03-13 09:54:06,189 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_create_connection:810 - Created connection: <ssl.SSLSocket fd=8, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.66.144.3', 36230), raddr=('10.2.77.208', 443)>
2023-03-13 09:54:06,519 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_update_smoothed_response_time:1173 - Response time: 0.00011515617370605469, Smoothed response time: 0.00011515617370605469
2023-03-13 09:54:06,580 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1127 - Response: status=200, requestUuid=d7dfea63-aaee-47f5-b961-a839767fe256, request="GET /subscription/status/"
2023-03-13 09:54:06,581 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1133 - Server wants to close connection. Closing HTTP connection
2023-03-13 09:54:06,581 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1093 - Making request: GET /subscription/status
2023-03-13 09:54:06,583 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_create_connection:772 - Creating new connection
2023-03-13 09:54:07,540 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_create_connection:810 - Created connection: <ssl.SSLSocket fd=8, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.66.144.3', 36236), raddr=('10.2.77.208', 443)>
2023-03-13 09:54:07,878 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_update_smoothed_response_time:1173 - Response time: 0.00010967254638671875, Smoothed response time: 0.00011460781097412109
2023-03-13 09:54:07,934 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1127 - Response: status=200, requestUuid=cc64a3b5-a7cc-45e3-8cb3-4af8a8ca1796, request="GET /subscription/status"
2023-03-13 09:54:07,934 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1133 - Server wants to close connection. Closing HTTP connection
2023-03-13 09:54:07,934 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_load_manager_capabilities:1427 - Server has the following capabilities: ['keycloak_auth', 'cloud_registration', 'instance_multiplier', 'derived_product', 'vcpu', 'cert_v3', 'hypervisors_heartbeat', 'remove_by_pool_id', 'syspurpose', 'storage_band', 'device_auth', 'cores', 'ssl_verify_status', 'multi_environment', 'hypervisors_async', 'org_level_content_access', 'guest_limit', 'ram', 'batch_bind', 'combined_reporting']
2023-03-13 09:54:07,934 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1093 - Making request: PUT /subscription/hypervisors/xxx/heartbeat?reporter_id=hp-z220-05.qe.lab.eng.nay.redhat.com-0df187d5b26b461ea384904b34d89fd4
2023-03-13 09:54:07,936 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_create_connection:772 - Creating new connection
2023-03-13 09:54:08,895 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_create_connection:810 - Created connection: <ssl.SSLSocket fd=8, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.66.144.3', 36246), raddr=('10.2.77.208', 443)>
2023-03-13 09:54:09,240 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_update_smoothed_response_time:1173 - Response time: 0.00011348724365234375, Smoothed response time: 0.00011449575424194335
2023-03-13 09:54:09,287 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1127 - Response: status=404, requestUuid=beeee21a-2fea-4c31-8102-00a7e56e5874, request="PUT /subscription/hypervisors/xxx/heartbeat?reporter_id=hp-z220-05.qe.lab.eng.nay.redhat.com-0df187d5b26b461ea384904b34d89fd4"
2023-03-13 09:54:09,287 [rhsm.connection DEBUG] MainProcess(481643):Thread-3 @connection.py:_request:1133 - Server wants to close connection. Closing HTTP connection
2023-03-13 09:54:09,287 [virtwho.destination_484620994773772658 ERROR] MainProcess(481643):Thread-3 @virt.py:_send_data:721 - Error during heartbeat: Communication with subscription manager failed with code 404: HTTP error (404 - Not Found): Organization with id xxx could not be found.
Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/virtwho/manager/subscriptionmanager/subscriptionmanager.py", line 270, in hypervisorHeartbeat
    result = connection.hypervisorHeartbeat(config['owner'], named_options)
  File "/usr/lib64/python3.9/site-packages/rhsm/connection.py", line 1605, in hypervisorHeartbeat
    return self.conn.request_put(url, description=_("Updating hypervisor information"))
  File "/usr/lib64/python3.9/site-packages/rhsm/connection.py", line 1325, in request_put
    result: Dict[str, Any] = self._request(
  File "/usr/lib64/python3.9/site-packages/rhsm/connection.py", line 1159, in _request
    self.validateResult(result, request_type, handler)
  File "/usr/lib64/python3.9/site-packages/rhsm/connection.py", line 1242, in validateResult
    raise RestlibException(result["status"], error_msg, result.get("headers"))
rhsm.connection.RestlibException: HTTP error (404 - Not Found): Organization with id xxx could not be found.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/virtwho/virt/virt.py", line 716, in _send_data
    self.dest.hypervisorHeartbeat(config=self.config, options=self.options)
  File "/usr/lib/python3.9/site-packages/virtwho/manager/subscriptionmanager/subscriptionmanager.py", line 279, in hypervisorHeartbeat
    raise ManagerError("Communication with subscription manager failed with code %d: %s" % (e.code, str(e)))
virtwho.manager.manager.ManagerError: Communication with subscription manager failed with code 404: HTTP error (404 - Not Found): Organization with id xxx could not be found.
2023-03-13 09:54:09,288 [virtwho.destination_484620994773772658 DEBUG] MainProcess(481643):Thread-3 @virt.py:_send_data:819 - ErrorReport received for source: virtwho-config
2023-03-13 09:54:09,288 [virtwho.destination_484620994773772658 DEBUG] MainProcess(481643):Thread-3 @virt.py:_send_data:925 - At least one report for each connected source has been sent. Terminating.
2023-03-13 09:54:09,288 [virtwho.destination_484620994773772658 DEBUG] MainProcess(481643):Thread-3 @virt.py:run:541 - Thread 'destination_484620994773772658' terminated
2023-03-13 09:54:10,232 [virtwho.main DEBUG] MainProcess(481643):MainThread @__main__.py:main:24 - virt-who terminated
2023-03-13 09:54:10,232 [virtwho.main DEBUG] MainProcess(481643):MainThread @main.py:exit:261 - None
2023-03-13 09:54:10,232 [virtwho.main DEBUG] MainProcess(481643):MainThread @executor.py:terminate:272 - virt-who is shutting down


3. Check the virt-who status

# virt-who --status
+-------------------------------------------+
           Configuration Status
+-------------------------------------------+
Configuration Name: virtwho-config
Source Status: success.   ----LOOK HERE
Destination Status: failure


# virt-who --status --json
{
    "configurations": [
        {
            "name": "virtwho-config",
            "source": {
                "connection": "10.73.131.xxx",
                "status": "success",     ----LOOK HERE
                "last_successful_retrieve": "2023-03-13 13:34:24 UTC",
                "hypervisors": 1,
                "guests": 1
            },
            "destination": {
                "connection": "subscription.rhsm.stage.redhat.com",
                "status": "failure",
                "message": "Error during status connection: Communication with subscription manager failed with code 404: HTTP error (404 - Not Found): Organization with id xxx could not be found..",
                "last_successful_send": "2023-03-13 13:34:33 UTC",
                "last_successful_send_job_status": null
            }
        }
    ]
}


Expected results:
The source status should also be failure.

Comment 1 RHEL Program Management 2023-10-10 10:56:06 UTC
Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug.

Comment 2 RHEL Program Management 2023-10-10 10:57:56 UTC
This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there.

Due to differences in account names between systems, some fields were not replicated.  Be sure to add yourself to Jira issue's "Watchers" field to continue receiving updates and add others to the "Need Info From" field to continue requesting information.

To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "RHEL-" followed by an integer.  You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like:

"Bugzilla Bug" = 1234567

In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. You can also visit https://access.redhat.com/articles/7032570 for general account information.


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