Note: This bug is displayed in read-only format because
the product is no longer active in Red Hat Bugzilla.
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.
Created attachment 1887050[details]
virt-install.log from a kickstart test run on RHEL 9.0
+++ This bug was initially created as a clone of Bug #2076948 +++
Description of problem:
In daily kickstart tests we have seen this failure in the logs:
01:22:35,674 WARNING org.fedoraproject.Anaconda.Modules.Subscription:DEBUG:anaconda.modules.subscription.initialization:subscription: setting RHSM log level to DEBUG
01:22:35,675 WARNING org.fedoraproject.Anaconda.Modules.Subscription:INFO:dasbus.connection:Connecting to the system bus.
01:22:35,675 WARNING org.fedoraproject.Anaconda.Modules.Subscription:INFO:dasbus.connection:Connecting to the system bus.
01:22:35,896 INFO rhsm-service:WARNING [rhsm.logutil:170] logging already initialized
01:22:35,911 INFO rhsm-service:DEBUG [rhsmlib.file_monitor:186] Thread Thread-FileSystemWatcher: Some event occurred: /etc/rhsm (/etc/rhsm/rhsm.conf)
01:22:35,944 INFO rhsm-service:ERROR [rhsmlib.dbus.util:41] No section: 'logging'
01:22:35,944 INFO rhsm-service:Traceback (most recent call last):
01:22:35,944 INFO rhsm-service: File "/usr/lib64/python3.6/site-packages/rhsmlib/dbus/util.py", line 38, in dbus_handle_exceptions
01:22:35,944 INFO rhsm-service: ret = func(*args, **kwargs)
01:22:35,944 INFO rhsm-service: File "/usr/lib64/python3.6/site-packages/rhsmlib/dbus/objects/config.py", line 151, in SetAll
01:22:35,944 INFO rhsm-service: rhsm.logutil.init_logger(parser)
01:22:35,944 INFO rhsm-service: File "/usr/lib64/python3.6/site-packages/rhsm/logutil.py", line 213, in init_logger
01:22:35,944 INFO rhsm-service: for logger_name, logging_level in config.items('logging'):
01:22:35,944 INFO rhsm-service: File "/usr/lib64/python3.6/site-packages/rhsm/config.py", line 278, in items
01:22:35,944 INFO rhsm-service: super_result = super(RhsmConfigParser, self).options(section)
01:22:35,944 INFO rhsm-service: File "/usr/lib/python3.6/site-packages/iniparse/compat.py", line 80, in options
01:22:35,944 INFO rhsm-service: raise NoSectionError(section)
01:22:35,944 INFO rhsm-service:configparser.NoSectionError: No section: 'logging'
01:22:35,959 INFO rhsm-service:DEBUG [rhsmlib.dbus.objects.config:214] files read: ['/etc/rhsm/rhsm.conf']
01:22:35,960 INFO rhsm-service:WARNING [rhsm.logutil:170] logging already initialized
01:22:35,978 WARNING org.fedoraproject.Anaconda.Modules.Subscription:INFO:anaconda.threading:Thread Failed: AnaTaskThread-StartRHSMTask-1 (140677725214464)
01:22:36,000 INFO rhsm-service:DEBUG [rhsmlib.dbus.objects.config:217] Configuration file: /etc/rhsm/rhsm.conf reloaded: {'server': "[('hostname', 'subscription.rhsm.redhat.com'), ('prefix', '/subscription'), ('port', '443'), ('server_timeout', '180'), ('insecure', '0'), ('ssl_verify_depth', '3'), ('proxy_hostname', ''), ('proxy_scheme', 'http'), ('proxy_user', ''), ('proxy_port', ''), ('proxy_password', ''), ('no_proxy', '')]", 'rhsm': "[('baseurl', 'https://cdn.redhat.com'), ('repomd_gpg_url', ''), ('ca_cert_dir', '/etc/rhsm/ca/'), ('repo_ca_cert', '/etc/rhsm/ca/redhat-uep.pem'), ('productcertdir', '/etc/pki/product'), ('entitlementcertdir', '/etc/pki/entitlement'), ('consumercertdir', '/etc/pki/consumer'), ('manage_repos', '1'), ('full_refresh_on_yum', '0'), ('report_package_profile', '1'), ('plugindir', '/usr/share/rhsm-plugins'), ('pluginconfdir', '/etc/rhsm/pluginconf.d'), ('auto_enable_yum_plugins', '1'), ('package_profile_on_trans', '0'), ('inotify', '1')]", 'rhsmcertd': "[('certcheckinterval', '240'), ('autoattachinterval', '1440'), ('splay', '1'), ('disable', '0'), ('auto_registration', '0'), ('auto_registration_interval', '60')]", 'logging': "[('default_log_level', 'DEBUG')]"}
01:22:36,010 INFO rhsm-service:DEBUG [rhsmlib.dbus.objects.config:54] D-Bus signal com.redhat.RHSM1.Config emitted
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription:ERROR:anaconda.modules.common.task.task:Thread AnaTaskThread-StartRHSMTask-1 has failed: Traceback (most recent call last):
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: File "/usr/lib64/python3.6/site-packages/pyanaconda/threading.py", line 280, in run
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: threading.Thread.run(self)
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: File "/usr/lib64/python3.6/threading.py", line 885, in run
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: self._target(*self._args, **self._kwargs)
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/common/task/task.py", line 97, in _task_run_callback
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: self._set_result(self.run())
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/subscription/initialization.py", line 94, in run
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: rhsm_config_proxy.SetAll(config_dict, "")
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 447, in _call_method
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: **kwargs,
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: return self._handle_method_error(error)
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription: raise exception from None
01:22:36,014 WARNING org.fedoraproject.Anaconda.Modules.Subscription:dasbus.error.DBusError: {"exception": "NoSectionError", "severity": "error", "message": "No section: 'logging'"}
01:22:36,017 WARNING org.fedoraproject.Anaconda.Modules.Subscription:INFO:anaconda.threading:Thread Done: AnaTaskThread-StartRHSMTask-1 (140677725214464)
01:22:36,440 WARNING org.fedoraproject.Anaconda.Modules.Security:DEBUG:anaconda.modules.common.base.base:Publish the service.
01:22:36,479 WARNING org.fedoraproject.Anaconda.Modules.Security:DEBUG:dasbus.connection:Publishing an object at /org/fedoraproject/Anaconda/Modules/Security.
Version-Release number of selected component (if applicable):
RHEL 8.6 development compose
anaconda 33.16.6.7-1.el8
How reproducible:
Happened in 2/1351 tests last week (happened on Saturday, Sunday)
The tests don't seem to be related directly to rhsm module, so probably a race condition. The failed tests:
ntp-nontp-without-chrony (log attached)
http://file.brq.redhat.com/rvykydal/daily_kstest_logs/kstest-ntp-nontp-without-chrony.2022_04_17-01_19_39.wli2o5ol/
url-baseurl
http://file.brq.redhat.com/rvykydal/daily_kstest_logs/kstest-url-baseurl.2022_04_18-01_36_44.b90ep42e/
Steps to Reproduce:
1.
2.
3.
Actual results:
Task AnaTaskThread-StartRHSMTask-1 fails with traceback
Expected results:
No traceback
Additional info:
Seems to be extremely rare.
--- Additional comment from Jiri Konecny on 2022-05-06 08:47:04 UTC ---
Hi Radku, if this will happen more often or again in the next minor RHEL releases, please comment here in the bug.
We've seen the issue for the first time in daily kickstart tests on RHEL 9. So it seems to be occuring much more rarely than on RHEL 8 (original of this clone).
Note on reproducibility: we hit the issue in our daily kickstart tests (we run ~200 tests each daily)
RHEL 8: ~ 1/700 tests
RHEL 9: ~ 1/6000 tests
We are able to run about 800 tests per day if we use all the resources that we do not use for current CI and daily workflows.
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-2023:6606