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 2078827 - subscription-manager prints traceback to rhsm.log during registration, when VM is running on Hyper-V
Summary: subscription-manager prints traceback to rhsm.log during registration, when V...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 9
Classification: Red Hat
Component: subscription-manager
Version: 9.0
Hardware: Unspecified
OS: Linux
unspecified
unspecified
Target Milestone: rc
: 9.1
Assignee: Jiri Hnidek
QA Contact: Red Hat subscription-manager QE Team
URL:
Whiteboard:
Depends On: 2056896
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-04-26 10:07 UTC by Rehana
Modified: 2022-11-15 13:13 UTC (History)
6 users (show)

Fixed In Version: subscription-manager-1.29.29-1.el9
Doc Type: If docs needed, set a value
Doc Text:
Clone Of: 2056896
Environment:
Last Closed: 2022-11-15 11:19:30 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github candlepin subscription-manager pull 2984 0 None Merged 2056896: Handle all exceptions of gathering data properly 2022-06-09 16:23:02 UTC
Red Hat Issue Tracker RHELPLAN-119957 0 None None None 2022-04-26 10:14:36 UTC
Red Hat Product Errata RHBA-2022:8341 0 None None None 2022-11-15 11:19:46 UTC

Description Rehana 2022-04-26 10:07:38 UTC 
+++ This bug was initially created as a clone of Bug #2056896 +++

Description of problem:
When system is running on virtual machine and Hyper-V is used as hypervisor, then subscription-manager can print traceback to rhsm.log. We can see this issue, when there is machine in LAN with following address 169.254.169.254 and it ignores HTTP requests. This happens, because subscription-manager tries to detect public cloud using heuristics from system facts. When Hyper-V is used as hypervisor, then it false positive detection can happen. Thus subscription-manager tries to gather metadata from IMDS server.


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

[root@localhost ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 3.2.22-1
subscription management rules: 5.41
subscription-manager: 1.28.21-3.el8


How reproducible:
100%


Steps to Reproduce:
1. Try to register system


Actual results:
System is registered, but following traceback is printed to rhsm.log


Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/subscription_manager/managercli.py", line 1863, in _do_command
    consumer = service.register(
  File "/usr/lib/python3/dist-packages/rhsmlib/services/register.py", line 85, in register
    facts_dict = self.facts.get_facts()
  File "/usr/lib/python3/dist-packages/subscription_manager/facts.py", line 78, in get_facts
    facts = collector.get_all()
  File "/usr/lib/python3/dist-packages/rhsmlib/facts/all.py", line 41, in get_all
    fact_collector = fact_collector_cls(collected_hw_info=results)
  File "/usr/lib/python3/dist-packages/rhsmlib/facts/cloud_facts.py", line 46, in __init__
    self.cloud_provider = get_cloud_provider(self._collected_hw_info)
  File "/usr/lib/python3/dist-packages/cloud_what/provider.py", line 149, in get_cloud_provider
    metadata = cloud_provider.get_metadata()
  File "/usr/lib/python3/dist-packages/cloud_what/providers/azure.py", line 235, in get_metadata
    return super(AzureCloudProvider, self).get_metadata()
  File "/usr/lib/python3/dist-packages/cloud_what/_base_provider.py", line 474, in get_metadata
    return self._get_metadata_from_server()
  File "/usr/lib/python3/dist-packages/cloud_what/providers/azure.py", line 195, in _get_metadata_from_server
    metadata = super(AzureCloudProvider, self)._get_metadata_from_server()
  File "/usr/lib/python3/dist-packages/cloud_what/_base_provider.py", line 402, in _get_metadata_from_server
    self._cached_metadata = self._get_data_from_server(
  File "/usr/lib/python3/dist-packages/cloud_what/providers/azure.py", line 188, in _get_data_from_server
    return super(AzureCloudProvider, self)._get_data_from_server(data_type, url, headers)
  File "/usr/lib/python3/dist-packages/cloud_what/_base_provider.py", line 387, in _get_data_from_server
    response = self._session.send(prepared_http_req, timeout=self.TIMEOUT)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPConnectionPool(host='169.254.169.254', port=80): Read timed out. (read timeout=10.0)


Expected results:
No traceback is printed to rhsm.log


Additional info:
System facts contains following informations:

{
  ...
  "dmi.chassis.manufacturer": "microsoft",
  "virt.host_type": "hyperv",
  "virt.is_guest": true,
  ...
}

This BZ was created based on the discussion in this community PR: https://github.com/candlepin/subscription-manager/pull/2947
Comment 1 Jan Stavel 2022-05-12 18:56:55 UTC 
I have verified that error message appears in rhsm.log instead of a raw traceback.

[root@bootp-73-131-184 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.2.22-1
subscription management rules: 5.41
subscription-manager: 1.29.26-3.el9_0

In case an origina IP address is used in file /usr/lib64/python3.9/site-packages/cloud_what/providers/azure.py 

this error appears in rhsm.log: 

    2022-05-12 13:48:35,897 [DEBUG] subscription-manager:10346:MainThread @provider.py:81 - Trying to detect cloud provider
    2022-05-12 13:48:35,899 [DEBUG] subscription-manager:10346:MainThread @provider.py:99 - No cloud provider detected using strong signs
    2022-05-12 13:48:35,901 [DEBUG] subscription-manager:10346:MainThread @provider.py:114 - Cloud provider aws has probability: 0.0
    2022-05-12 13:48:35,903 [DEBUG] subscription-manager:10346:MainThread @provider.py:114 - Cloud provider azure has probability: 0.6
    2022-05-12 13:48:35,905 [DEBUG] subscription-manager:10346:MainThread @provider.py:114 - Cloud provider gcp has probability: 0.0
    2022-05-12 13:48:35,907 [DEBUG] subscription-manager:10346:MainThread @provider.py:125 - Following cloud providers detected using heuristics: azure
    2022-05-12 13:48:35,925 [DEBUG] subscription-manager:10346:MainThread @_base_provider.py:373 - Trying to get metadata from http://169.254.169.254/metadata/instance?api-version=2021-02-01
    2022-05-12 13:48:35,934 [DEBUG] subscription-manager:10346:MainThread @_base_provider.py:387 - Unable to get azure metadata: HTTPConnectionPool(host='169.254.169.254', port=80): Max retries exceeded with url: /metadata/instance?api-version=2021-02-01 (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f3ee4d08850>: Failed to establish a new connection: [Errno 113] No route to host'))
    2022-05-12 13:48:35,935 [DEBUG] subscription-manager:10346:MainThread @_base_provider.py:373 - Trying to get api_versions from http://169.254.169.254/metadata/versions
    2022-05-12 13:48:35,939 [DEBUG] subscription-manager:10346:MainThread @_base_provider.py:387 - Unable to get azure api_versions: HTTPConnectionPool(host='169.254.169.254', port=80): Max retries exceeded with url: /metadata/versions (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f3ee4d08c10>: Failed to establish a new connection: [Errno 113] No route to host'))
    2022-05-12 13:48:35,940 [ERROR] subscription-manager:10346:MainThread @azure.py:143 - Unable to decode Azure API versions: the JSON object must be str, bytes or bytearray, not NoneType
    2022-05-12 13:48:35,940 [DEBUG] subscription-manager:10346:MainThread @provider.py:161 - Unable to get metadata from any cloud provider detected using heuristics


After I change the IP address 169.254.169.254 to IP address of our dummy service (it drops all packets only) I see this error in rhsm.log:

2022-05-12 14:22:15,285 [DEBUG] subscription-manager:11435:MainThread @provider.py:81 - Trying to detect cloud provider
2022-05-12 14:22:15,287 [DEBUG] subscription-manager:11435:MainThread @provider.py:99 - No cloud provider detected using strong signs
2022-05-12 14:22:15,291 [DEBUG] subscription-manager:11435:MainThread @provider.py:114 - Cloud provider aws has probability: 0.0
2022-05-12 14:22:15,292 [DEBUG] subscription-manager:11435:MainThread @provider.py:114 - Cloud provider azure has probability: 0.6
2022-05-12 14:22:15,294 [DEBUG] subscription-manager:11435:MainThread @provider.py:114 - Cloud provider gcp has probability: 0.0
2022-05-12 14:22:15,299 [DEBUG] subscription-manager:11435:MainThread @provider.py:125 - Following cloud providers detected using heuristics: azure
2022-05-12 14:22:15,300 [DEBUG] subscription-manager:11435:MainThread @_base_provider.py:373 - Trying to get metadata from http://10.8.29.160/metadata/instance?api-version=2021-02-01
2022-05-12 14:22:25,333 [DEBUG] subscription-manager:11435:MainThread @_base_provider.py:387 - Unable to get azure metadata: HTTPConnectionPool(host='10.8.29.160', port=80): Max retries exceeded with url: /metadata/instance?api-version=2021-02-01 (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x7f0369240850>, 'Connection to 10.8.29.160 timed out. (connect timeout=10.0)'))
2022-05-12 14:22:25,336 [DEBUG] subscription-manager:11435:MainThread @_base_provider.py:373 - Trying to get api_versions from http://10.8.29.160/metadata/versions
2022-05-12 14:22:35,374 [DEBUG] subscription-manager:11435:MainThread @_base_provider.py:387 - Unable to get azure api_versions: HTTPConnectionPool(host='10.8.29.160', port=80): Max retries exceeded with url: /metadata/versions (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x7f0369240c40>, 'Connection to 10.8.29.160 timed out. (connect timeout=10.0)'))
2022-05-12 14:22:35,378 [ERROR] subscription-manager:11435:MainThread @azure.py:146 - Unable to decode Azure API versions: the JSON object must be str, bytes or bytearray, not NoneType
2022-05-12 14:22:35,379 [DEBUG] subscription-manager:11435:MainThread @provider.py:161 - Unable to get metadata from any cloud provider detected using heuristics


I have not set override.facts. IE. subscription-manager made mistake itself.


the scenario I've run:

   ... set DEBUG values in rhsm.conf
   ... set stage candlepin
   ... set stage CDN service
   ... export SUBMAN_DEBUG_PRINT_REQUEST=1 subscription-manager register --auto-attach
Comment 5 Jan Stavel 2022-07-25 11:44:12 UTC 
Good morning,
I have not met any traceback in rhsm.log.

A playbook for this case attached.

2022-07-25 14:36:20,053 [DEBUG] subscription-manager:24904:MainThread @custom.py:85 - Loading custom facts from: /etc/rhsm/facts/override.facts
2022-07-25 14:36:20,053 [DEBUG] subscription-manager:24904:MainThread @provider.py:102 - Trying to detect cloud provider
2022-07-25 14:36:20,054 [DEBUG] subscription-manager:24904:MainThread @provider.py:122 - No cloud provider detected using strong signs
2022-07-25 14:36:20,054 [DEBUG] subscription-manager:24904:MainThread @provider.py:142 - Cloud provider aws has probability: 0.0
2022-07-25 14:36:20,054 [DEBUG] subscription-manager:24904:MainThread @provider.py:142 - Cloud provider azure has probability: 0.7
2022-07-25 14:36:20,055 [DEBUG] subscription-manager:24904:MainThread @provider.py:142 - Cloud provider gcp has probability: 0.0
2022-07-25 14:36:20,055 [DEBUG] subscription-manager:24904:MainThread @provider.py:153 - Following cloud providers detected using heuristics: azure
2022-07-25 14:36:20,055 [DEBUG] subscription-manager:24904:MainThread @_base_provider.py:391 - Trying to get metadata from http://169.254.169.254/metadata/instance?api-version=2021-02-01
2022-07-25 14:36:30,068 [DEBUG] subscription-manager:24904:MainThread @_base_provider.py:405 - Unable to get azure metadata: HTTPConnectionPool(host='169.254.169.254', port=80): Max retries exceeded with url: /metadata/instance?api-version=2021-02-01 (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x7f391f4eedf0>, 'Connection to 169.254.169.254 timed out. (connect timeout=10.0)'))
2022-07-25 14:36:30,069 [DEBUG] subscription-manager:24904:MainThread @_base_provider.py:391 - Trying to get api_versions from http://169.254.169.254/metadata/versions
2022-07-25 14:36:40,081 [DEBUG] subscription-manager:24904:MainThread @_base_provider.py:405 - Unable to get azure api_versions: HTTPConnectionPool(host='169.254.169.254', port=80): Max retries exceeded with url: /metadata/versions (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x7f391f4ef1f0>, 'Connection to 169.254.169.254 timed out. (connect timeout=10.0)'))
2022-07-25 14:36:40,081 [ERROR] subscription-manager:24904:MainThread @azure.py:152 - Unable to decode Azure API versions: the JSON object must be str, bytes or bytearray, not NoneType
2022-07-25 14:36:40,081 [DEBUG] subscription-manager:24904:MainThread @provider.py:198 - Unable to get metadata from any cloud provider detected using heuristics
2022-07-25 14:36:40,081 [DEBUG] subscription-manager:24904:MainThread @profile.py:92 - This system is not running on AWS. Skipping fixing of RHUI repos.
2022-07-25 14:36:49,713 [DEBUG] subscription-manager:24904:MainThread @connection.py:1028 - Making request: PUT /subscription/consumers/c03d7aa7-2e52-4afa-94d9-ca4a64c93eef/profiles
2022-07-25 14:36:49,719 [DEBUG] subscription-manager:24904:MainThread @connection.py:711 - Connection timeout 30. Closing connection...
2022-07-25 14:36:49,719 [DEBUG] subscription-manager:24904:MainThread @connection.py:625 - Closing HTTPS connection <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.35.59.17', 43168), raddr=('10.2.77.208', 443)>
2022-07-25 14:36:49,786 [DEBUG] subscription-manager:24904:MainThread @connection.py:631 - TLS connection closed
2022-07-25 14:36:49,787 [DEBUG] subscription-manager:24904:MainThread @connection.py:726 - Creating new connection
2022-07-25 14:36:50,230 [DEBUG] subscription-manager:24904:MainThread @connection.py:755 - Created connection: <ssl.SSLSocket fd=5, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.35.59.17', 36202), raddr=('10.2.77.208', 443)>


    PACKAGES TESTED:
    subscription-manager-1.29.29-1.el9.x86_64
    package subscription-manager-cockpit is not installed
    subscription-manager-rhsm-certificates-20220623-1.el9.noarch
    package subscription-manager-initial-setup-addon is not installed
    package dnf-plugin-subscription-manager is not installed
    python3-cloud-what-1.29.29-1.el9.x86_64
    python3-subscription-manager-rhsm-1.29.29-1.el9.x86_64
    package python3-syspurpose is not installed
    package rhsm-gtk is not installed
    package rhsm-icons is not installed
    package subscription-manager-migration is not installed
    package subscription-manager-migration-data is not installed
    package subscription-manager-plugin-ostree is not installed
Comment 7 errata-xmlrpc 2022-11-15 11:19:30 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 (subscription-manager 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/RHBA-2022:8341
Note You need to log in before you can comment on or make changes to this bug.