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 2025825 - anaconda timeouts waiting on timezone module
Summary: anaconda timeouts waiting on timezone module
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Red Hat Enterprise Linux 9
Classification: Red Hat
Component: anaconda
Version: CentOS Stream
Hardware: Unspecified
OS: Unspecified
urgent
urgent
Target Milestone: rc
: ---
Assignee: Anaconda Maintenance Team
QA Contact: Release Test Team
URL:
Whiteboard:
Depends On:
Blocks: oVirt_on_CentOS_Stream_9_Hosts
TreeView+ depends on / blocked
 
Reported: 2021-11-23 06:47 UTC by Sandro Bonazzola
Modified: 2022-02-08 11:01 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-02-08 11:01:00 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker RHELPLAN-103620 0 None None None 2021-11-23 06:49:53 UTC

Description Sandro Bonazzola 2021-11-23 06:47:05 UTC 
While building oVirt Node based on CentOS Stream 9, virt-install is now failing with:

00:41:19 23:41:40,819 WARNING org.fedoraproject.Anaconda.Modules.Security:DEBUG:anaconda.modules.common.base.base:Publish the service.
00:41:41 23:41:42,951 WARNING org.fedoraproject.Anaconda.Modules.Security:DEBUG:dasbus.connection:Publishing an object at /org/fedoraproject/Anaconda/Modules/Security.
00:41:44 23:41:45,274 WARNING org.fedoraproject.Anaconda.Modules.Security:INFO:anaconda.core.dbus:Connecting to the Anaconda bus at unix:abstract=/tmp/dbus-3FCiESFRrB,guid=64cd48adc739e96a5c63b029619ad724.
00:41:46 23:42:14,042 WARNING org.fedoraproject.Anaconda.Modules.Security:DEBUG:dasbus.connection:Registering a service name org.fedoraproject.Anaconda.Modules.Security.
00:42:15 23:42:16,693 INFO dbus-daemon:Successfully activated service 'org.fedoraproject.Anaconda.Modules.Security'
00:42:19 23:42:16,874 WARNING org.fedoraproject.Anaconda.Modules.Security:DEBUG:anaconda.modules.common.base.base:Start the loop.
00:42:19 23:42:19,521 WARNING org.fedoraproject.Anaconda.Boss:DEBUG:anaconda.modules.boss.module_manager.start_modules:Service org.fedoraproject.Anaconda.Modules.Security started successfully.
00:42:20 23:42:20,720 WARNING org.fedoraproject.Anaconda.Boss:DEBUG:anaconda.modules.boss.module_manager.start_modules:org.fedoraproject.Anaconda.Modules.Security is available.
00:42:21 23:42:26,919 WARNING org.fedoraproject.Anaconda.Addons.OSCAP:DEBUG:anaconda.modules.common.base.base:Publish the service.
00:42:30 23:42:36,354 WARNING org.fedoraproject.Anaconda.Addons.OSCAP:DEBUG:dasbus.connection:Publishing an object at /org/fedoraproject/Anaconda/Addons/OSCAP.
00:42:37 23:42:36,585 WARNING org.fedoraproject.Anaconda.Addons.OSCAP:INFO:anaconda.core.dbus:Connecting to the Anaconda bus at unix:abstract=/tmp/dbus-3FCiESFRrB,guid=64cd48adc739e96a5c63b029619ad724.
00:42:37 23:42:39,280 WARNING org.fedoraproject.Anaconda.Modules.Timezone:INFO:root:reading file=<gzip _io.BufferedReader name='/usr/lib/python3.9/site-packages/langtable/data/keyboards.xml.gz' 0x7f504b094130>
00:42:40 23:42:44,417 WARNING org.fedoraproject.Anaconda.Modules.Timezone:INFO:root:reading file=<gzip _io.BufferedReader name='/usr/lib/python3.9/site-packages/langtable/data/timezones.xml.gz' 0x7f504b79c6d0>
00:42:45 23:42:44,553 WARNING org.fedoraproject.Anaconda.Modules.Timezone:INFO:root:reading file=<gzip _io.BufferedReader name='/usr/lib/python3.9/site-packages/langtable/data/timezoneidparts.xml.gz' 0x7f504b2e4eb0>
00:42:45 23:42:46,905 WARNING org.fedoraproject.Anaconda.Modules.Storage:INFO:program:Running [2] lvm version ...
00:42:47 23:42:50,366 WARNING org.fedoraproject.Anaconda.Modules.Payloads:DEBUG:anaconda.modules.common.base.base:Publish the service.
00:42:51 23:42:50,908 WARNING org.fedoraproject.Anaconda.Modules.Payloads:DEBUG:dasbus.connection:Publishing an object at /org/fedoraproject/Anaconda/Modules/Payloads.
00:42:51 23:42:51,227 WARNING org.fedoraproject.Anaconda.Modules.Payloads:INFO:anaconda.core.dbus:Connecting to the Anaconda bus at unix:abstract=/tmp/dbus-3FCiESFRrB,guid=64cd48adc739e96a5c63b029619ad724.
00:42:51 23:42:51,436 WARNING org.fedoraproject.Anaconda.Addons.OSCAP:DEBUG:dasbus.connection:Registering a service name org.fedoraproject.Anaconda.Addons.OSCAP.
00:42:52 23:42:52,843 INFO dbus-daemon:Successfully activated service 'org.fedoraproject.Anaconda.Addons.OSCAP'
00:42:53 23:42:53,284 WARNING org.fedoraproject.Anaconda.Addons.OSCAP:DEBUG:anaconda.modules.common.base.base:Start the loop.
00:42:54 23:42:55,280 WARNING org.fedoraproject.Anaconda.Boss:DEBUG:anaconda.modules.boss.module_manager.start_modules:Service org.fedoraproject.Anaconda.Addons.OSCAP started successfully.
00:42:56 23:42:55,562 WARNING org.fedoraproject.Anaconda.Boss:DEBUG:anaconda.modules.boss.module_manager.start_modules:org.fedoraproject.Anaconda.Addons.OSCAP is available.
00:42:56 23:42:59,099 WARNING org.fedoraproject.Anaconda.Modules.Payloads:DEBUG:dasbus.connection:Registering a service name org.fedoraproject.Anaconda.Modules.Payloads.
00:42:59 23:43:00,492 INFO dbus-daemon:Successfully activated service 'org.fedoraproject.Anaconda.Modules.Payloads'
00:43:01 23:43:00,562 WARNING org.fedoraproject.Anaconda.Modules.Payloads:DEBUG:anaconda.modules.common.base.base:Start the loop.
00:43:01 23:43:00,898 WARNING org.fedoraproject.Anaconda.Boss:DEBUG:anaconda.modules.boss.module_manager.start_modules:Service org.fedoraproject.Anaconda.Modules.Payloads started successfully.
00:43:01 23:43:00,969 WARNING org.fedoraproject.Anaconda.Boss:DEBUG:anaconda.modules.boss.module_manager.start_modules:org.fedoraproject.Anaconda.Modules.Payloads is available.
00:43:01 23:43:13,297 WARNING org.fedoraproject.Anaconda.Modules.Localization:INFO:root:reading file=<gzip _io.BufferedReader name='/usr/lib/python3.9/site-packages/langtable/data/keyboards.xml.gz' 0x7f2f79c580d0>
00:43:14 23:43:19,253 NOTICE dbus-daemon:Failed to activate service 'org.fedoraproject.Anaconda.Modules.Timezone': timed out (service_start_timeout=600000ms)
00:43:19 23:43:20,241 NOTICE dbus-daemon:Failed to activate service 'org.fedoraproject.Anaconda.Modules.Localization': timed out (service_start_timeout=600000ms)
00:43:20 23:43:20,341 NOTICE dbus-daemon:Failed to activate service 'org.fedoraproject.Anaconda.Modules.Users': timed out (service_start_timeout=600000ms)
00:43:20 23:43:21,384 WARNING org.fedoraproject.Anaconda.Modules.Localization:INFO:root:reading file=<gzip _io.BufferedReader name='/usr/lib/python3.9/site-packages/langtable/data/timezones.xml.gz' 0x7f2f79c589d0>
00:43:21 23:43:21,544 WARNING org.fedoraproject.Anaconda.Modules.Localization:INFO:root:reading file=<gzip _io.BufferedReader name='/usr/lib/python3.9/site-packages/langtable/data/timezoneidparts.xml.gz' 0x7f2f79c58040>
00:43:21 23:43:22,651 WARNING org.fedoraproject.Anaconda.Boss:INFO:anaconda.threading:Thread Failed: AnaTaskThread-StartModulesTask-1 (140620689708608)
00:43:23 23:43:23,086 WARNING org.fedoraproject.Anaconda.Modules.Storage:INFO:program:stdout[2]:   LVM version:     2.03.14(2) (2021-10-20)
00:43:23 23:43:23,086 WARNING org.fedoraproject.Anaconda.Modules.Storage:  Library version: 1.02.181 (2021-10-20)
00:43:23 23:43:23,086 WARNING org.fedoraproject.Anaconda.Modules.Storage:  Driver version:  4.45.0
00:43:23 23:43:23,086 WARNING org.fedoraproject.Anaconda.Modules.Storage:  Configuration:   ./configure --build=x86_64-redhat-linux-gnu --host=x86_64-redhat-linux-gnu --program-prefix= --disable-dependency-tracking --prefix=/usr --exec-prefix=/usr --bindir=/usr/bin --sbindir=/usr/sbin --sysconfdir=/etc --datadir=/usr/share --includedir=/usr/include --libdir=/usr/lib64 --libexecdir=/usr/libexec --localstatedir=/var --sharedstatedir=/var/lib --mandir=/usr/share/man --infodir=/usr/share/info --with-default-dm-run-dir=/run --with-default-run-dir=/run/lvm --with-default-pid-dir=/run --with-default-locking-dir=/run/lock/lvm --with-usrlibdir=/usr/lib64 --enable-fsadm --enable-write_install --with-user= --with-group= --with-device-uid=0 --with-device-gid=6 --with-device-mode=0660 --enable-pkgconfig --enable-cmdlib --enable-dmeventd --enable-blkid_wiping --with-cluster=internal --with-udevdir=/usr/lib/udev/rules.d --enable-udev_sync --with-thin=internal --with-cache=internal --enable-lvmpolld --enable-lvmlockd-dlm --enable-lvmlockd-dlmcontrol --enable-lvmlockd-sanlock --enable-dbus-service --enable-notify-dbus --enable-dmfilemapd --with-writecache=internal --with-vdo=internal --with-vdo-format=/usr/bin/vdoformat --with-integrity=internal --disable-silent-rules --enable-app-machineid --enable-editline --disable-readline
00:43:23 23:43:24,065 WARNING org.fedoraproject.Anaconda.Modules.Storage:INFO:program:stderr[2]:
00:43:24 23:43:24,833 WARNING org.fedoraproject.Anaconda.Modules.Storage:INFO:program:...done [2] (exit code: 0)
00:43:25 23:43:25,276 NOTICE dbus-daemon:Failed to activate service 'org.fedoraproject.Anaconda.Modules.Storage': timed out (service_start_timeout=600000ms)
00:43:25 23:43:25,479 NOTICE dbus-daemon:Failed to activate service 'org.fedoraproject.Anaconda.Modules.Services': timed out (service_start_timeout=600000ms)
00:43:25 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:ERROR:anaconda.modules.common.task.task:Thread AnaTaskThread-StartModulesTask-1 has failed: Traceback (most recent call last):
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 136, in _start_service_by_name_handler
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    returned = call()
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 460, in <lambda>
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    lambda: self._get_method_reply(getter),
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    return self._handle_method_error(error)
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    raise exception from None
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:dasbus.error.DBusError: Failed to activate service 'org.fedoraproject.Anaconda.Modules.Timezone': timed out (service_start_timeout=600000ms)
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:The above exception was the direct cause of the following exception:
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:Traceback (most recent call last):
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/site-packages/pyanaconda/threading.py", line 275, in run
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    threading.Thread.run(self)
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/threading.py", line 910, in run
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    self._target(*self._args, **self._kwargs)
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/common/task/task.py", line 96, in _thread_run_callback
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    self._task_run_callback()
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/common/task/task.py", line 109, in _task_run_callback
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    self._set_result(self.run())
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 74, in run
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    self._process_callbacks(self._module_observers)
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 184, in _process_callbacks
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    is_available = callback(observer)
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 138, in _start_service_by_name_handler
00:43:27 23:43:25,574 WARNING org.fedoraproject.Anaconda.Boss:    raise UnavailableModuleError(
00:43:27 23:43:25,662 WARNING org.fedoraproject.Anaconda.Boss:pyanaconda.modules.common.errors.module.UnavailableModuleError: Service org.fedoraproject.Anaconda.Modules.Timezone has failed to start: Failed to activate service 'org.fedoraproject.Anaconda.Modules.Timezone': timed out (service_start_timeout=600000ms)
00:43:27 23:43:25,700 WARNING org.fedoraproject.Anaconda.Boss:INFO:anaconda.threading:Thread Done: AnaTaskThread-StartModulesTask-1 (140620689708608)
00:43:27 2021-11-21 18:43:26,945: Installation error detected. See logfile for details.
00:43:27 2021-11-21 18:43:26,948: VirtualInstall failed: QEMUInstall failed
00:43:27 2021-11-21 18:43:26,949: unmounting the iso
00:43:27 2021-11-21 18:43:27,421: Install failed: QEMUInstall failed


This started to happen around November 15th. 

The job is running here: https://jenkins.ovirt.org/job/ovirt-node-ng-image_master_build-artifacts-el9stream-x86_64/
you can get both the successfull build logs and the failing build log
Comment 1 Jan Stodola 2021-11-23 09:22:52 UTC 
Hello,
such timeouts usually happen on system with poor performance. Could you please check the system you are using to build the images?

Even in case of a successful run (build 70), it took 13 minutes to (re)generate initramfs, which seems to be quite slow:

01:25:35 00:25:34,616 WARNING org.fedoraproject.Anaconda.Modules.Storage:INFO:program:Running in chroot '/mnt/sysroot'... dracut -f /boot/initramfs-5.14.0-12.el9.x86_64.img 5.14.0-12.el9.x86_64
01:38:47 00:38:46,702 WARNING org.fedoraproject.Anaconda.Modules.Storage:DEBUG:program:Return code: 0
Comment 2 Sandro Bonazzola 2021-11-23 14:02:56 UTC 
The system is a 12 GB ram VM with 2 VCPUs Westmere E56xx/L56xx/X56xx (Nehalem-C) @2GHz 
# dd if=/dev/zero of=/tmp/test1.img bs=1G count=1 oflag=dsync
1+0 records in
1+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 27.9559 s, 38.4 MB/s
Comment 3 Jan Stodola 2022-01-14 14:36:02 UTC 
Sandro,
can you please confirm this issue is still happening? Unfortunately I could not find any failed jenkins job in the link from comment 0 that would fail due to the problem described in this bug.
Comment 4 Sandro Bonazzola 2022-02-08 11:01:00 UTC 
I'm not able to reproduce this anymore, closing this as works for me now.
Note You need to log in before you can comment on or make changes to this bug.