networking.service: start operation timed out
In Debian 11/bullseye my system keeps reporting timeouts while trying
to bring up the first non-loopback interface. According to ip, the
interface actually is up, but ifup/down do not know that. My 2nd
interface is down, and there is no mention of attempting to bring it
up in the logs. I can bring up both interfaces after startup,
suggesting there may be something special about the initial
environment that is causing trouble, but I don't know what.
I'd appreciate any suggestions about how to diagnose or cure the
problem. I have set VERBOSE=yes in /etc/default/networking
When I started the errors were coming on a bridge interface;
suspecting a bridge-specific problem I disabled the bridge (comment
out the auto br0 in /etc/network/interface). Now I have the exact
same problem with a vanilla declaration for a lan.
My machine has 2 physical ethernet ports, resolvconf, KDE,
network-manager, bridge-utils, tor, and nftables. I have systemctl
disable'd NetworkManager and tor, though with no visible effect.
NetworkManager was mentioning the interfaces controlled by
/etc/network/interfaces, but it wasn't clearly doing anything to them,
and the default options do say to leave them alone. I have customized
scripts for networking and resolvconf.
------------------------------------- /etc/network/interfaces
----------------------------
# The next directory is empty
# many posts about similar problems had an interfaces.d/setup file
causing trouble
source /etc/network/interfaces.d/*
# The loopback network interface
auto lo
iface lo inet loopback
rename enp5s0=ethlan
rename eno2=ethworld
auto ethlan
iface ethlan inet static
address 192.168.1.10/24
# not sure if it makes sense to be my own gateway
# gateway 192.168.1.10
broadcast 192.168.1.255
dns-domain betterworld.us
dns-search betterworld.us
#auto br0
iface br0 inet static
# details omitted, presumed irrelevant
auto ethworld
iface ethworld inet static
address 66.181.128.36/24 # IP obscured
gateway 66.181.128.1
# I am my own nameserver, but next is a fallback
dns-nameservers N.N.N.N
pre-up /etc/network/rb-iface-manage up # brings up firewall.
takes a few seconds.
post-down /etc/network/rb-iface-manage down
post-down ip route add default dev ethlan
--------------- journalctl -b -u networking
--------------------------------------------
-- Journal begins at Thu 2022-05-19 12:21:39 PDT, ends at Fri
2022-08-26 11:58:07 PDT. --
Aug 26 11:55:19 barley ifup[1563]: /sbin/ip link set enp5s0 name ethlan
Aug 26 11:55:19 barley ifup[1563]: /sbin/ip link set eno2 name ethworld
Aug 26 11:55:19 barley ifup[1563]: /bin/run-parts --exit-on-error
--verbose /etc/network/if-pre-up.d
Aug 26 11:55:19 barley ifup[1573]: run-parts: executing
/etc/network/if-pre-up.d/bridge
Aug 26 11:55:19 barley ifup[1573]: run-parts: executing
/etc/network/if-pre-up.d/vde2
Aug 26 11:55:19 barley ifup[1573]: run-parts: executing
/etc/network/if-pre-up.d/wpasupplicant
Aug 26 11:55:18 barley systemd[1]: Starting Raise network interfaces...
Aug 26 11:55:19 barley ifup[1563]: ifup: configuring interface lo=lo (inet)
Aug 26 11:55:19 barley ifup[1563]: /bin/run-parts --exit-on-error
--verbose /etc/network/if-pre-up.d
Aug 26 11:55:19 barley ifup[1583]: run-parts: executing
/etc/network/if-pre-up.d/bridge
Aug 26 11:55:19 barley ifup[1583]: run-parts: executing
/etc/network/if-pre-up.d/vde2
Aug 26 11:55:19 barley ifup[1583]: run-parts: executing
/etc/network/if-pre-up.d/wpasupplicant
Aug 26 11:55:19 barley ifup[1563]: /sbin/ip link set dev lo up
Aug 26 11:55:19 barley ifup[1563]: /bin/run-parts --exit-on-error
--verbose /etc/network/if-up.d
Aug 26 11:55:19 barley ifup[1590]: run-parts: executing
/etc/network/if-up.d/000resolvconf
Aug 26 11:55:19 barley ifup[1590]: run-parts: executing
/etc/network/if-up.d/bind9
Aug 26 11:55:20 barley ifup[1590]: run-parts: executing
/etc/network/if-up.d/chrony
Aug 26 11:55:20 barley ifup[1590]: run-parts: executing
/etc/network/if-up.d/wpasupplicant
Aug 26 11:55:20 barley ifup[1563]: ifup: configuring interface
ethlan=ethlan (inet)
Aug 26 11:55:20 barley ifup[1563]: /bin/run-parts --exit-on-error
--verbose /etc/network/if-pre-up.d
Aug 26 11:55:20 barley ifup[1658]: run-parts: executing
/etc/network/if-pre-up.d/bridge
Aug 26 11:55:20 barley ifup[1658]: run-parts: executing
/etc/network/if-pre-up.d/vde2
Aug 26 11:55:20 barley ifup[1658]: run-parts: executing
/etc/network/if-pre-up.d/wpasupplicant
Aug 26 11:55:20 barley ifup[1563]: /sbin/ip addr add
192.168.1.10/255.255.255.0 broadcast 192.168.1.255 dev
ethlan label ethlan
Aug 26 11:55:20 barley ifup[1563]: /sbin/ip link set dev ethlan up
Aug 26 11:55:20 barley ifup[1563]: /bin/run-parts --exit-on-error
--verbose /etc/network/if-up.d
Aug 26 11:55:20 barley ifup[1680]: run-parts: executing
/etc/network/if-up.d/000resolvconf
Aug 26 11:56:18 barley systemd[1]: networking.service: start operation
timed out. Terminating.
Aug 26 11:56:18 barley ifup[1563]: Got signal Terminated, terminating...
Aug 26 11:56:18 barley ifup[1563]: ifup: failed to bring up ethlan
Aug 26 11:56:18 barley ifup[1691]: Terminated
Aug 26 11:56:18 barley ifup[1691]: Terminated
Aug 26 11:56:18 barley systemd[1]: networking.service: Main process
exited, code=exited, status=1/FAILURE
Aug 26 11:56:18 barley systemd[1]: networking.service: Failed with
result 'timeout'.
Aug 26 11:56:18 barley systemd[1]: Failed to start Raise network interfaces.
---------------------------------------------
Comments.
1. The man page for ifup -a says interfaces will be brought up in the
order specified. OTOH, man interfaces says calls to different
interfaces can be run in parallel. Although this doesn't logically
imply ifup -a (which is what the networking.service uses) brings
things up in parallel, it kind of looks above as if that's what's
happening.
2. There are 3 if-pre-up.d sections (for lo, ethlan, ethworld?) and 2
if-up.d sections. None are explicitly labelled with which interface
they are being run for. Perhaps it can be inferred from earlier and
later loglines. The 2nd if-up.d section has only the first run-parts
script mentioned.
3. lo and ethlan are both brought up by ip
4. ifup doesn't really fail; it is killed by systemd after
networking.service's timeout (which I lowered to 1m from 5) expires.
It clearly doesn't do much to bring up ethworld.
5. Presumably the problem is that ifup -a never completes. The logs
suggest that if-up.d/000resolvconf is where it hangs up, which I
suppose means it might actually be in one of resolvconf's scripts that
it hangs up. However, the ip route for ethlan is set when the system
comes up.
6. Or maybe it's the next script, if-up.d/bind9 which is the problem.
000resolvconf is as packaged, while bind9 is a local creation, though
based on package resolvconf's advice. I.e., the bind9 script is more
likely to have a bug.
7. After all this, ifdown ethlan fails with the message the interface
is not up, despite what ip link says. ifdown --force ethlan; ifup -v
ethlan; ifup -v ethworld then bring both interfaces up. ifup returns
without error from each.
8. Some of the triggered scripts are about updating bind and
isc-dhcp-server. As networking services, I presume they are not yet
active when networking is being set up. The scripts seem to have
appropriate defenses in place, but maybe something is off. For
example, if-up.d/bind9 has `/usr/sbin/rndc reconfig >/dev/null 2>&1
|| :`. My assumption was that rndc would fail if bind9 were not
running, and that the `|| :` would conceal the failure. If rndc
blocks awaiting a response, that would hang things up. FWIW, if I
stop named and run rndc reconfig I get an immediate failure.
Reply to: