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 1911300 - Anaconda fails to install from kickstart with : Service org.fedoraproject.Anaconda.Modules.Network has failed to start: Failed to activate service 'org.fedoraproject.Anaconda.Modules.Network': timed out (service_start_timeout=600000ms)
Summary: Anaconda fails to install from kickstart with : Service org.fedoraproject.Ana...
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: systemd
Version: 8.3
Hardware: x86_64
OS: Linux
high
high
Target Milestone: rc
: 8.0
Assignee: systemd-maint
QA Contact: Frantisek Sumsal
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-12-28 16:19 UTC by Florian Sachs
Modified: 2022-05-23 08:33 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-05-23 08:33:08 UTC
Type: Bug
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
kickstart file (5.97 KB, text/plain)
2020-12-28 16:20 UTC, Florian Sachs
no flags Details
program.log (548 bytes, text/plain)
2020-12-28 16:20 UTC, Florian Sachs
no flags Details
storage.log (25.35 KB, text/plain)
2020-12-28 16:21 UTC, Florian Sachs
no flags Details
anaconda.log (5.16 KB, text/plain)
2020-12-28 16:21 UTC, Florian Sachs
no flags Details
dbus.log (6.59 KB, text/plain)
2020-12-28 16:21 UTC, Florian Sachs
no flags Details
terminal output (728 bytes, text/plain)
2020-12-28 16:22 UTC, Florian Sachs
no flags Details
journal log for the anaconda run (67.52 KB, text/plain)
2020-12-28 16:22 UTC, Florian Sachs
no flags Details
lshw output (73.67 KB, application/xhtml+xml)
2020-12-28 16:22 UTC, Florian Sachs
no flags Details
Logs from run with higher timeout and selinux dontaudit rules not shown (36.09 KB, application/gzip)
2021-01-07 10:54 UTC, Florian Sachs
no flags Details
Logs from run with higher timeout and semodule -db run before anaconda start (41.09 KB, application/gzip)
2021-01-07 10:54 UTC, Florian Sachs
no flags Details

Description Florian Sachs 2020-12-28 16:19:17 UTC
Description of problem:
We use a custom Live Image to install via "anaconda -d --kickstart /path/to/kickstart". The custom Live ISO is used so we can configure the local hardware (detect and configure different raid controllers, Management cards, ...) before we call anaconda with the kickstart file. The kickstart file is based on a template, which itself is enhanced with the hardware-related information (installdevice like /dev/sda or /dev/vda, bind the network on a given mac address and so on, install necessary sofware (hardware raid tools if needed)


Switching from RHEL 8.2 to RHEL 8.3, anaconda stopped working. I use the identical config for KVM/libvirt.

Version-Release number of selected component (if applicable):
anaconda-33.16.3.26-2.el8_3.x86_64
kernel-4.18.0-240.1.1.el8_3.x86_64

How reproducible:

Configure network in advance as planned, call installer.

Steps to Reproduce:
1. nmcli con add con-name enp1s0 type ethernet ifname enp1s0 ipv4.method manual ip4 10.26.200.131/23 gw4 10.26.201.254 ipv4.dns "10.26.251.2,10.176.250.2" ipv6.method ignore ipv6.never-default true
2. anaconda -d --kickstart /tmp/kamino.ks

Actual results:

[root@jakkutest01 tmp]# cat /etc/redhat-release
Red Hat Enterprise Linux release 8.3 (Ootpa)


[root@jakkutest01 tmp]# anaconda -d --kickstart /tmp/kamino.ks
Starting installer, one moment...
anaconda 33.16.3.26-2.el8_3 for anaconda bluesky (pre-release) started.
 * installation log files are stored in /tmp during the installation
 * shell is available on TTY2 and in second TMUX pane (ctrl+b, then press 2)
 * if the graphical installation interface fails to start, try again with the
   inst.text bootoption to start text installation
 * when reporting a bug add logs from /tmp as separate text/plain attachments
17:03:21 Service org.fedoraproject.Anaconda.Modules.Network has failed to start: Failed to activate service 'org.fedoraproject.Anaconda.Modules.Network': timed out (service_start_timeout=600000ms)


Expected results:
Installation works as in RHEL 8.2

Additional info:
Will upload kickstart file and logs.

Comment 1 Florian Sachs 2020-12-28 16:20:19 UTC
Created attachment 1742727 [details]
kickstart file

Comment 2 Florian Sachs 2020-12-28 16:20:47 UTC
Created attachment 1742728 [details]
program.log

Comment 3 Florian Sachs 2020-12-28 16:21:07 UTC
Created attachment 1742729 [details]
storage.log

Comment 4 Florian Sachs 2020-12-28 16:21:23 UTC
Created attachment 1742730 [details]
anaconda.log

Comment 5 Florian Sachs 2020-12-28 16:21:40 UTC
Created attachment 1742731 [details]
dbus.log

Comment 6 Florian Sachs 2020-12-28 16:22:02 UTC
Created attachment 1742732 [details]
terminal output

Comment 7 Florian Sachs 2020-12-28 16:22:24 UTC
Created attachment 1742733 [details]
journal log for the anaconda run

Comment 8 Florian Sachs 2020-12-28 16:22:44 UTC
Created attachment 1742734 [details]
lshw output

Comment 9 Jiri Konecny 2021-01-05 11:20:25 UTC
Seems that systemd-hostnamed service took too much time to get ready and our Network module is waiting on this service. However, it could be that it just need more time. Could you please increase timeout by changing value:

<limit name="service_start_timeout">600000</limit>

in file:

/usr/share/anaconda/dbus/anaconda-bus.conf



Try to change it to 1800000 (half an hour) and if you will see the failure again please post us new logs.

Comment 10 Florian Sachs 2021-01-05 15:56:45 UTC
Thank you for pointing me into the direction of systemd-hostnamed.

The problem seems to be related to selinux and looks very like https://bugzilla.redhat.com/show_bug.cgi?id=1663040

If I do "setenforce 0" prior to calling anaconda, the installation works and the installed system seems to work using selinux in enforcing mode.

Do you still need the asked-for information from me?

Comment 11 Jiri Konecny 2021-01-06 11:06:32 UTC
I'm not sure that this is the issue. Main reason is that hostnamed was started, late but started.

Dec 28 16:53:52 jakkutest01.3ve.bmlv.at systemd[1]: systemd-hostnamed.service: Succeeded.


I wonder what role SELinux is taking here because I don't see any denials in the log. Could you please still test the timeout and look on /var/log/audit/audit.log if there are any denials?

Comment 12 Florian Sachs 2021-01-07 10:54:06 UTC
Created attachment 1745263 [details]
Logs from run with higher timeout and selinux dontaudit rules not shown

Comment 13 Florian Sachs 2021-01-07 10:54:39 UTC
Created attachment 1745265 [details]
Logs from run with higher timeout and semodule -db run before anaconda start

Comment 15 jcastran 2021-06-28 19:46:12 UTC
Hello,

We have an installation case with 8.4 (4.18.0-305.el8.x86_64) and this exact error.

# tail -n1 /tmp/dbus.log
  Failed to activate service 'org.fedoraproject.Anaconda.Modules.Network': timed out (service_start_timeout=600000ms)

Mentioned in https://bugzilla.redhat.com/show_bug.cgi?id=1919380, that was closed saying it wasn't an issue in the 8.4 beta kernel. 

23:16:38,104 INFO dbus-daemon:[system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.3' (uid=0 pid=161443 comm="/usr/sbin/NetworkManager --no-daemon " label="system_u:system_r:kernel_t:s0")
23:17:03,106 NOTICE dbus-daemon:[system] Failed to activate service 'org.freedesktop.hostname1': timed out (service_start_timeout=25000ms)
23:17:56,355 INFO systemd:systemd-hostnamed.service: Succeeded.

There are tracebacks as well.

23:28:52,251 NOTICE dbus-daemon:Failed to activate service 'org.fedoraproject.Anaconda.Modules.Network': timed out (service_start_timeout=600000ms)
23:28:52,252 WARNING org.fedoraproject.Anaconda.Boss:INFO:anaconda.threading:Thread Failed: AnaTaskThread-StartModulesTask-1 (139700450182912)
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:ERROR:anaconda.modules.common.task.task:Thread AnaTaskThread-StartModulesTask-1 has failed: Traceback (most recent call last):
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 143, in _start_service_by_
name_handler
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    returned = call()
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 460, in <lambda>
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    lambda: self._get_method_reply(getter),
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    return self._handle_method_error(error)
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib/python3.6/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    raise exception from None
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:dasbus.error.DBusError: Failed to activate service 'org.fedoraproject.Anaconda.Modules.Network': timed out (service_start_timeout=60
0000ms)
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:The above exception was the direct cause of the following exception:
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:Traceback (most recent call last):
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.6/site-packages/pyanaconda/threading.py", line 280, in run
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    threading.Thread.run(self)
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.6/threading.py", line 864, in run
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    self._target(*self._args, **self._kwargs)
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/common/task/task.py", line 97, in _task_run_callback
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    self._set_result(self.run())
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 81, in run
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    unavailable.discard(callback())
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 138, in <lambda>
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    self._callbacks.put(lambda: self._start_service_by_name_handler(*args, **kwargs))
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:  File "/usr/lib64/python3.6/site-packages/pyanaconda/modules/boss/module_manager/start_modules.py", line 147, in _start_service_by_
name_handler
23:28:52,253 WARNING org.fedoraproject.Anaconda.Boss:    ) from error
23:28:52,254 WARNING org.fedoraproject.Anaconda.Boss:pyanaconda.modules.common.errors.module.UnavailableModuleError: Service org.fedoraproject.Anaconda.Modules.Network has failed to start: Failed to activate service 'org.fedoraproject.Anaconda.Modules.Network': timed out (service_start_timeout=600000ms)


From what I can see, this installation should be using the iso as the source and no networking is required. Is there any way to disable or prevent this module? Is this the right bug, or do I need to open a new bug (or reopen 1919380)?

Comment 17 jcastran 2021-06-28 19:56:21 UTC
Did we ever find out if increasing the timeout worked?

> However, it could be that it just need more time. Could you please increase timeout by changing value:

> <limit name="service_start_timeout">600000</limit>

> in file:

> /usr/share/anaconda/dbus/anaconda-bus.conf


This could potentially be modified during installation with an updates.img if so

Comment 19 Jiri Konecny 2022-01-06 13:46:11 UTC
(In reply to jcastran from comment #17)
> Did we ever find out if increasing the timeout worked?
> 
> > However, it could be that it just need more time. Could you please increase timeout by changing value:
> 
> > <limit name="service_start_timeout">600000</limit>
> 
> > in file:
> 
> > /usr/share/anaconda/dbus/anaconda-bus.conf
> 
> 
> This could potentially be modified during installation with an updates.img
> if so

Yes, it should be possible to set bigger timeout with the updates image but I don't think that is a way to go forward. If the machine is not super slow it shouldn't be a problem and the timeout should be enough. I'm more convinced that there is some issue happening under the hood which is blocking the module.

Comment 20 David Tardon 2022-01-07 13:55:56 UTC
(In reply to Jiri Konecny from comment #14)
> Potential duplicate of this issue is bug 1919380.
> 
> The correct fix may go to Anaconda (see comment 4 on bug 1919380), however,
> I would like to leave this bug on systemd to investigate why turning off
> selinux will make the hostnamed service faster.

This looks like a variation of bug 1694681: something--anaconda in this case--makes a DBus call, but SELinux blocks the reply, so the call timeouts. Can we see the respective audit message(s)?

Comment 21 Florian Sachs 2022-05-23 07:08:53 UTC
Sorry for completely forgetting. As this is more than a year old, I think this can be closed. If I encounter similar problems in 8.5/8.6, I will open an new ticket-


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