Bug 1911300
Summary: | 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) | ||||||||||||||||||||||||
---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
Product: | Red Hat Enterprise Linux 8 | Reporter: | Florian Sachs <florian.sachs> | ||||||||||||||||||||||
Component: | systemd | Assignee: | systemd-maint | ||||||||||||||||||||||
Status: | CLOSED INSUFFICIENT_DATA | QA Contact: | Frantisek Sumsal <fsumsal> | ||||||||||||||||||||||
Severity: | high | Docs Contact: | |||||||||||||||||||||||
Priority: | high | ||||||||||||||||||||||||
Version: | 8.3 | CC: | anaconda-maint-list, dtardon, florian.sachs, jcastran, jkonecny, massi.ergosum, sbarcomb, systemd-maint-list | ||||||||||||||||||||||
Target Milestone: | rc | ||||||||||||||||||||||||
Target Release: | 8.0 | ||||||||||||||||||||||||
Hardware: | x86_64 | ||||||||||||||||||||||||
OS: | Linux | ||||||||||||||||||||||||
Whiteboard: | |||||||||||||||||||||||||
Fixed In Version: | Doc Type: | If docs needed, set a value | |||||||||||||||||||||||
Doc Text: | Story Points: | --- | |||||||||||||||||||||||
Clone Of: | Environment: | ||||||||||||||||||||||||
Last Closed: | 2022-05-23 08:33:08 UTC | Type: | Bug | ||||||||||||||||||||||
Regression: | --- | Mount Type: | --- | ||||||||||||||||||||||
Documentation: | --- | CRM: | |||||||||||||||||||||||
Verified Versions: | Category: | --- | |||||||||||||||||||||||
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||||||||||||||
Cloudforms Team: | --- | Target Upstream Version: | |||||||||||||||||||||||
Embargoed: | |||||||||||||||||||||||||
Attachments: |
|
Description
Florian Sachs
2020-12-28 16:19:17 UTC
Created attachment 1742727 [details]
kickstart file
Created attachment 1742728 [details]
program.log
Created attachment 1742729 [details]
storage.log
Created attachment 1742730 [details]
anaconda.log
Created attachment 1742731 [details]
dbus.log
Created attachment 1742732 [details]
terminal output
Created attachment 1742733 [details]
journal log for the anaconda run
Created attachment 1742734 [details]
lshw output
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. 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? 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? Created attachment 1745263 [details]
Logs from run with higher timeout and selinux dontaudit rules not shown
Created attachment 1745265 [details]
Logs from run with higher timeout and semodule -db run before anaconda start
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)? 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 (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. (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)? 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- |