[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
bug#60300: Premature networking started status with NetworkManager
From: |
mirai |
Subject: |
bug#60300: Premature networking started status with NetworkManager |
Date: |
Sat, 24 Dec 2022 16:23:09 +0000 |
User-agent: |
Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Thunderbird/102.6.0 |
If a service has a requirement on 'networking
(either from accepting a shepherd-requirements field from its configuration
record-type or
from the service-type definition) and networking is provided by NetworkManager,
it will not
work as intended. This is because networking is prematurely flagged as started
before
NetworkManager can finish its startup.
Some of the visible consequences resulting from this is service startup failure
for OpenSMTPD when it's configured with a non-loopback interface and has a
dependency on 'networking
placed using shepherd-requirement field.
A similar situation happens with nginx, failure to start the service or ignored
directives that
want to resolve domains over DNS.
These failures do not happen if one creates a one-shot simple-service that puts
a dependency on networking
and simply waits approx. 10-30 seconds and have nginx-service-type or
opensmptd-service-type depend on it
instead.
>From /var/log/messages (truncated to relevant parts):
--8<---------------cut here---------------start------------->8---
Dec 21 22:19:01 localhost shepherd[1]: Service networking has been started.
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6330]
NetworkManager (version 1.41.2) is starting... (asserts:100,
boot:502a84f9-92cc-47a9-a86c-97ec819fb23a)
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6331] Read
config: /gnu/store/3cp48fvxfivj2255bbxj7363qj33ajs9-NetworkManager.conf
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6340]
bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6353]
manager[0xc85080]: monitoring kernel firmware directory '/lib/firmware'.
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6357]
hostname: hostname: couldn't get property from hostnamed
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6358]
hostname: static hostname changed from (none) to "doll"
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6363]
dns-mgr: init: dns=default,systemd-resolved rc-manager=resolvconf (auto)
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6365]
manager[0xc85080]: rfkill: Wi-Fi hardware radio set enabled
Dec 21 22:19:01 localhost NetworkManager[473]: <info> [1671661141.6365]
manager[0xc85080]: rfkill: WWAN hardware radio set enabled
[...]
Dec 21 22:19:30 localhost shepherd[1]: Service nscd has been started.
Dec 21 22:19:30 localhost shepherd[1]: [NetworkManager] Service nscd has been
stopped.
Dec 21 22:19:30 localhost shepherd[1]: [NetworkManager] Service nscd has been
started.
Dec 21 22:19:30 localhost dbus-daemon[470]: [system] Activating service
name='org.freedesktop.nm_dispatcher' requested by ':1.1' (uid=0 pid=473
comm="/gnu/store/ghf1miwbxfcz33mx9bccllgf257vvfhp-networ") (using servicehelper)
Dec 21 22:19:30 localhost NetworkManager[473]: <info> [1671661170.2951] device
(enp4s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state:
'managed')
Dec 21 22:19:30 localhost dbus-daemon[470]: [system] Successfully activated
service 'org.freedesktop.nm_dispatcher'
Dec 21 22:19:30 localhost NetworkManager[473]: <info> [1671661170.2995] device
(enp4s0): state change: ip-check -> secondaries (reason 'none',
sys-iface-state: 'managed')
Dec 21 22:19:30 localhost NetworkManager[473]: <info> [1671661170.2996] device
(enp4s0): state change: secondaries -> activated (reason 'none',
sys-iface-state: 'managed')
Dec 21 22:19:30 localhost NetworkManager[473]: <info> [1671661170.2998]
manager: NetworkManager state is now CONNECTED_SITE
Dec 21 22:19:30 localhost NetworkManager[473]: <info> [1671661170.2999] device
(enp4s0): Activation: successful, device activated.
Dec 21 22:19:30 localhost NetworkManager[473]: <info> [1671661170.3001]
manager: NetworkManager state is now CONNECTED_GLOBAL
Dec 21 22:19:30 localhost NetworkManager[473]: <info> [1671661170.3003]
manager: startup complete
--8<---------------cut here---------------end--------------->8---
It's apparent that 'networking should be flagged started only after
NetworkManager logs "startup complete".
- bug#60300: Premature networking started status with NetworkManager,
mirai <=