Uploaded image for project: 'RHEL'
  1. RHEL
  2. RHEL-12407

[Nutanix] virt-who always shows Source Status:success for nutanix mode

Linking RHIVOS CVEs to...Migration: Automation ...SWIFT: POC ConversionSync from "Extern...XMLWordPrintable

    • None
    • None
    • subs-client-tools-2
    • None
    • False
    • False
    • Hide

      None

      Show
      None
    • None
    • None
    • None
    • None
    • If docs needed, set a value
    • None
    • 57,005

      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

      1. 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

      1. 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

      1. virt-who --status
        -------------------------------------------
        Configuration Status
        -------------------------------------------
        Configuration Name: virtwho-config
        Source Status: success. ----LOOK HERE
        Destination Status: failure
      1. virt-who --status --json
        {
        "configurations": [
        Unknown macro: { "name"}

        ]
        }

      Expected results:
      The source status should also be failure.

              csi-client-tools-bugs CSI Client Tools Bugs Bot
              rhn-support-yuefliu Yuefen Liu
              CSI Client Tools Bugs Bot CSI Client Tools Bugs Bot
              CSI Client Tools Bugs Bot CSI Client Tools Bugs Bot
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

                Created:
                Updated:
                Resolved: