2076948 – [kickstart tests failure] 01:22:35,944 INFO rhsm-service:configparser.NoSectionError: No section: 'logging'

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 2076948 - [kickstart tests failure] 01:22:35,944 INFO rhsm-service:configparser.NoSectionError: No section: 'logging'

Summary: [kickstart tests failure] 01:22:35,944 INFO rhsm-service:configparser.NoSecti...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 8
Classification:	Red Hat
Component:	subscription-manager
Sub Component:
Version:	---
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	rc
Target Release:	8.9
Assignee:	Jiri Hnidek
QA Contact:	Jan Stodola
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	2093883
TreeView+	depends on / blocked

Reported:	2022-04-20 09:46 UTC by Radek Vykydal
Modified:	2023-11-14 17:58 UTC (History)
CC List:	4 users (show)
Fixed In Version:	subscription-manager-1.28.37-1.el8
Doc Type:	No Doc Update
Doc Text:
Clone Of:
Clones:	2093883 (view as bug list)
Environment:
Last Closed:	2023-11-14 15:47:57 UTC
Type:	Bug
Target Upstream Version:
Embargoed:
Dependent Products:

Attachments	(Terms of Use)
virt-install.log of the ntp-nontp-without-chrony test failure (41.72 KB, text/plain) 2022-04-20 09:46 UTC, Radek Vykydal	no flags	Details
View All

Links
System	ID	Priority	Status	Summary	Last Updated
Github	candlepin subscription-manager pull 3199	None	Merged	2076948: [1.28] Fix issue with race condition in rhsm.service	2023-03-17 20:08:16 UTC
Red Hat Issue Tracker	ENT-5383	None	None	None	2022-08-31 10:38:39 UTC
Red Hat Issue Tracker	RHELPLAN-119389	None	None	None	2022-04-20 09:50:12 UTC
Red Hat Product Errata	RHBA-2023:7092	None	None	None	2023-11-14 15:48:15 UTC

Description Radek Vykydal 2022-04-20 09:46:21 UTC

Created attachment 1873773 [details]
virt-install.log of the ntp-nontp-without-chrony test failure

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.

Comment 1 Jiri Konecny 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.

Comment 2 Radek Vykydal 2022-06-06 09:55:02 UTC

(In reply to Jiri Konecny from comment #1)
> Hi Radku, if this will happen more often or again in the next minor RHEL
> releases, please comment here in the bug.

Still seen with the same frequency on RHEL 8.6: 1/1351, 3/1351. We have seen it for the first time on RHEL 9.0: https://bugzilla.redhat.com/show_bug.cgi?id=2093883.
I'll confirm the situation for RHEL 8.7.

Comment 3 Jiri Konecny 2022-06-17 09:33:14 UTC

Martine, could you please quick look if this should be switched to the rhsm component? The traceback is clearly from their code, question is if this is because of invalid data we are giving them.

Comment 4 Martin Kolman 2022-08-30 09:37:47 UTC

(In reply to Jiri Konecny from comment #3)
> Martine, could you please quick look if this should be switched to the rhsm
> component? The traceback is clearly from their code, question is if this is
> because of invalid data we are giving them.

I think what we do is correct, but is seems like the config access is not atomic and it is possible to hit a time window, likely when the config file is being re/loaded, when RHSM things a given config section does not exist when we try to set a value in it. So reassigning to RHSM.

Comment 5 Martin Kolman 2022-08-30 09:52:09 UTC

Looks like there is another variant of this traceback in a recent test run (https://github.com/rhinstaller/kickstart-tests/issues/779):

01:29:32,837 WARNING org.fedoraproject.Anaconda.Modules.Subscription:INFO:anaconda.threading:Running Thread: AnaTaskThread-RestoreRHSMDefaultsTask-1 (140314837796608)
01:29:32,844 WARNING org.fedoraproject.Anaconda.Modules.Subscription:DEBUG:anaconda.modules.subscription.installation:subscription: setting RHSM log level back to INFO
01:29:32,844 WARNING org.fedoraproject.Anaconda.Modules.Subscription:DEBUG:anaconda.modules.subscription.installation:subscription: making sure RHSM SSL certificate validation is enabled
01:29:32,953 INFO rhsm-service:DEBUG [rhsmlib.dbus.objects.config:122] Setting new configuration values: {'logging.default_log_level': 'INFO', 'server.insecure': '0'}
01:29:32,958 INFO rhsm-service:DEBUG [rhsmlib.dbus.server:231] Disabling directory watcher: CONFIG_WATCHER
01:29:32,959 INFO rhsm-service:DEBUG [rhsmlib.file_monitor:307] Temporary disabled watcher: /etc/rhsm/rhsm.conf for 5 seconds
01:29:33,005 INFO rhsm-service:DEBUG [rhsmlib.file_monitor:186] Thread Thread-FileSystemWatcher: Some event occurred: /etc/rhsm (/etc/rhsm/tmpzqhtcgix)
01:29:33,006 INFO rhsm-service:DEBUG [rhsmlib.dbus.server:247] Enabling directory watcher: CONFIG_WATCHER
01:29:33,011 INFO rhsm-service:WARNING [rhsm.logutil:170] logging already initialized
01:29:33,120 INFO rhsm-service:ERROR [rhsmlib.dbus.util:41] 'Undefined' object is not iterable
01:29:33,120 INFO rhsm-service:Traceback (most recent call last):
01:29:33,120 INFO rhsm-service:  File "/usr/lib64/python3.6/site-packages/rhsmlib/dbus/util.py", line 38, in dbus_handle_exceptions
01:29:33,120 INFO rhsm-service:    ret = func(*args, **kwargs)
01:29:33,120 INFO rhsm-service:  File "/usr/lib64/python3.6/site-packages/rhsmlib/dbus/objects/config.py", line 151, in SetAll
01:29:33,120 INFO rhsm-service:    rhsm.logutil.init_logger(parser)
01:29:33,120 INFO rhsm-service:  File "/usr/lib64/python3.6/site-packages/rhsm/logutil.py", line 213, in init_logger
01:29:33,120 INFO rhsm-service:    for logger_name, logging_level in config.items('logging'):
01:29:33,120 INFO rhsm-service:  File "/usr/lib64/python3.6/site-packages/rhsm/config.py", line 278, in items
01:29:33,120 INFO rhsm-service:    super_result = super(RhsmConfigParser, self).options(section)
01:29:33,120 INFO rhsm-service:  File "/usr/lib/python3.6/site-packages/iniparse/compat.py", line 78, in options
01:29:33,120 INFO rhsm-service:    return list(self.data[section])
01:29:33,120 INFO rhsm-service:TypeError: 'Undefined' object is not iterable
01:29:33,157 INFO rhsm-service:WARNING [rhsm.logutil:170] logging already initialized
01:29:33,168 WARNING org.fedoraproject.Anaconda.Modules.Subscription:INFO:anaconda.threading:Thread Failed: AnaTaskThread-RestoreRHSMDefaultsTask-1 (140314837796608)
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:ERROR:anaconda.modules.common.task.task:Thread AnaTaskThread-RestoreRHSMDefaultsTask-1 has failed: Traceback (most recent call last):
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/site-packages/pyanaconda/threading.py", line 280, in run
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    threading.Thread.run(self)
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/threading.py", line 885, in run
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    self._target(*self._args, **self._kwargs)
01:29:33,206 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:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    self._set_result(self.run())
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/subscription/installation.py", line 126, in run
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    self._rhsm_config_proxy.SetAll(config_dict, "")
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 447, in _call_method
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    **kwargs,
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    return self._handle_method_error(error)
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    raise exception from None
01:29:33,206 WARNING org.fedoraproject.Anaconda.Modules.Subscription:dasbus.error.DBusError: {"exception": "TypeError", "severity": "error", "message": "'Undefined' object is not iterable"}
01:29:33,209 WARNING org.fedoraproject.Anaconda.Modules.Subscription:INFO:anaconda.threading:Thread Done: AnaTaskThread-RestoreRHSMDefaultsTask-1 (140314837796608)
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:WARNING:dasbus.server.handler:The call org.fedoraproject.Anaconda.Task.Finish has failed with an exception:
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:Traceback (most recent call last):
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/server/handler.py", line 421, in _method_callback
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    *unwrap_variant(parameters)
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/server/handler.py", line 234, in _handle_call
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    return handler(*parameters)
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/common/task/task_interface.py", line 114, in Finish
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    self.implementation.finish()
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/common/task/task.py", line 161, in finish
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    threadMgr.raise_if_error(self._thread_name)
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/site-packages/pyanaconda/threading.py", line 171, in raise_if_error
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    raise exc_info[0](exc_info[1]).with_traceback(exc_info[2])
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/site-packages/pyanaconda/threading.py", line 280, in run
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    threading.Thread.run(self)
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/threading.py", line 885, in run
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    self._target(*self._args, **self._kwargs)
01:29:33,861 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:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    self._set_result(self.run())
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/subscription/installation.py", line 126, in run
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    self._rhsm_config_proxy.SetAll(config_dict, "")
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 447, in _call_method
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    **kwargs,
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    return self._handle_method_error(error)
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:    raise exception from None
01:29:33,861 WARNING org.fedoraproject.Anaconda.Modules.Subscription:dasbus.error.DBusError: {"exception": "TypeError", "severity": "error", "message": "'Undefined' object is not iterable"}
01:29:33,894 INFO anaconda:anaconda: threading: Thread Failed: AnaInstallThread (139966820218624)
01:29:33,895 DEBUG anaconda:anaconda: exception: running handleException
01:29:33,913 CRIT anaconda:anaconda: exception: Traceback (most recent call last):#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/threading.py", line 280, in run#012    threading.Thread.run(self)#012#012  File "/usr/lib64/python3.6/threading.py", line 885, in run#012    self._target(*self._args, **self._kwargs)#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/installation.py", line 406, in run_installation#012    queue.start()#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/installation_tasks.py", line 311, in start#012    item.start()#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/installation_tasks.py", line 311, in start#012    item.start()#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/installation_tasks.py", line 311, in start#012    item.start()#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/installation_tasks.py", line 490, in start#012    self.run_task()#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/installation_tasks.py", line 521, in run_task#012    sync_run_task(self._task_proxy)#012#012  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/common/task/__init__.py", line 46, in sync_run_task#012    task_proxy.Finish()#012#012  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 447, in _call_method#012    **kwargs,#012#012  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply#012    return self._handle_method_error(error)#012#012  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error#012    raise exception from None#012#012dasbus.error.DBusError: {"exception": "TypeError", "severity": "error", "message": "'Undefined' object is not iterable"}
01:29:33,940 DEBUG anaconda:anaconda: exception: Gtk running, queuing exception handler to the main loop


Note that the test run (that does 160+ installations) did exhibit both the traceback noted above as well as the traceback described in bug description.

Comment 6 Radek Vykydal 2022-10-25 15:17:06 UTC

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.

Comment 7 Martin Kolman 2023-03-24 12:51:04 UTC

We have not seen the issue with the latest builds, so the fix seems to work as intended.

Comment 13 Radek Vykydal 2023-04-24 11:56:04 UTC

We are switching our daily kickstart-tests to RHEL 8.9 so we should see the issue disappearing from our regular tests. I'll post an update about the results into this BZ.

Comment 14 Radek Vykydal 2023-05-02 12:37:15 UTC

(In reply to Radek Vykydal from comment #13)
> We are switching our daily kickstart-tests to RHEL 8.9 so we should see the
> issue disappearing from our regular tests. I'll post an update about the
> results into this BZ.

We didn't see any occurrence of the issue last week. The week before (with RHEL 8.8) there was 9 instances.

Comment 15 Pino Toscano 2023-05-03 06:21:39 UTC

@Radek:

thanks for the updates, it looks promising! can you please also check the same issue in 9.3, i.e. bug 2093883?

Comment 16 Radek Vykydal 2023-05-03 07:42:56 UTC

(In reply to Pino Toscano from comment #15)
> @Radek:
> 
> thanks for the updates, it looks promising! can you please also check the
> same issue in 9.3, i.e. bug 2093883?

Okay, I'll update a bit later there because for RHEL 9 we used to hit the issue about only a few times per month.

Comment 17 Radek Vykydal 2023-06-13 11:50:43 UTC

(In reply to Radek Vykydal from comment #14)
> (In reply to Radek Vykydal from comment #13)
> > We are switching our daily kickstart-tests to RHEL 8.9 so we should see the
> > issue disappearing from our regular tests. I'll post an update about the
> > results into this BZ.
> 
> We didn't see any occurrence of the issue last week. The week before (with
> RHEL 8.8) there was 9 instances.

Still no occurrence, according to our daily kickstart tests the issue seems to be fixed.

Comment 19 Rehana 2023-06-27 11:00:56 UTC

Thanks for the confirmation Radek. Based on the confirmation from comment 17, there was no occurrences of this issue during the CTC1 test cycle. We consider this to be a good indicator for the provided patch. So moving the bug to verified.

Comment 21 errata-xmlrpc 2023-11-14 15:47:57 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-2023:7092

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