Created attachment 1840787 [details] dispatcher.d script for NetworkManager Description of problem: Host is configured to use DHCP configuration, but the (transient) hostname isn't getting the value of option 12 (via ${DHCP4_HOST_NAME}). Version-Release number of selected component (if applicable): NetworkManager-1.30.6-1.fc34.x86_64 How reproducible: Provision a VM, and provision a DHCP static lease for it with a fixed hostname. Have the VM configured to use DHCP on the active interface. Steps to Reproduce: 1. Create a VM and provision it to use DHCP address assignment 2. Provision a static DHCP lease to the VM's MAC address with a fixed hostname 3. Boot the VM, and run "hostname" Actual results: % hostname localhost.localdomain Expected results: Whatever hostname the lease was provisioned with Additional info: Copied from https://bugzilla.redhat.com/show_bug.cgi?id=974811#c39
I'm using the following script of /etc/NetworkManager/dispatcher.d/hostname.sh and getting the following logging (filtered for things like systemd and audit being excluded, and unrelated services like proftpd): Nov 8 15:57:35 localhost /usr/sbin/irqbalance[840]: libcap-ng used by "/usr/sbin/irqbalance" failed due to not having CAP_SETPCAP in capng_apply Nov 8 15:57:35 localhost rsyslogd[854]: [origin software="rsyslogd" swVersion="8.2102.0-3.fc34" x-pid="854" x-info="https://www.rsyslog.com"] start Nov 8 15:57:35 localhost systemd-resolved[800]: Defaulting to hostname 'fedora'. Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.0915] NetworkManager (version 1.30.6-1.fc34) is starting... (for the first time) Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.0915] Read config: /etc/NetworkManager/NetworkManager.conf Nov 8 15:57:35 localhost ip6tables.init[831]: ip6tables: Applying firewall rules: [ OK ] Nov 8 15:57:35 localhost ip6tables.init[831]: ip6tables: Loading additional modules: nf_conntrack_ftp nf_conntrack_tftp [ OK ] Nov 8 15:57:35 localhost systemd-logind[867]: New seat seat0. Nov 8 15:57:35 localhost systemd-logind[867]: Watching system buttons on /dev/input/event0 (Power Button) Nov 8 15:57:35 localhost systemd-logind[867]: Watching system buttons on /dev/input/event1 (AT Translated Set 2 keyboard) Nov 8 15:57:35 localhost journal[871]: Ready Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.3039] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager" Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.3148] manager[0x56356e123030]: monitoring kernel firmware directory '/lib/firmware'. Nov 8 15:57:35 localhost journal[908]: failed to get edid data: EDID length is too small Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8153] hostname: hostname: using hostnamed Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8155] hostname: hostname changed from (none) to "localhost.localdomain" Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8162] dns-mgr[0x56356e117170]: init: dns=default,systemd-resolved rc-manager=symlink (auto) Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8683] manager[0x56356e123030]: rfkill: Wi-Fi hardware radio set enabled Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8684] manager[0x56356e123030]: rfkill: WWAN hardware radio set enabled Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8770] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8774] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8776] manager: Networking is enabled by state file Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8789] dhcp-init: Using DHCP client 'dhclient' Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8807] settings: Loaded settings plugin: keyfile (internal) Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8852] settings: Loaded settings plugin: ifcfg-rh ("/usr/lib64/NetworkManager/1.30.6-1.fc34/libnm-settings-plugin-ifcfg-rh.so") Nov 8 15:57:35 localhost nm-dispatcher[931]: req:1 'hostname': new request (6 scripts) Nov 8 15:57:35 localhost nm-dispatcher[931]: req:1 'hostname': start running ordered scripts... Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.9364] device (lo): carrier: link connected Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.9411] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412255.9498] manager: (ens3): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2) Nov 8 15:57:36 localhost kernel: igbvf 0000:00:03.0: Link is Up 1000 Mbps Full Duplex Nov 8 15:57:36 localhost kernel: IPv6: ADDRCONF(NETDEV_CHANGE): ens3: link becomes ready Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412255.9597] device (ens3): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external') Nov 8 15:57:36 localhost nm-dispatcher[931]: req:2 'connectivity-change': new request (6 scripts) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.0504] device (ens3): carrier: link connected Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.0834] device (ens3): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed') Nov 8 15:57:36 localhost iptables.init[836]: iptables: Applying firewall rules: [ OK ] Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1123] policy: auto-activating connection 'System ens3' (db7b64ba-a781-4456-8a0f-9d41a8e8904b) Nov 8 15:57:36 localhost iptables.init[836]: iptables: Loading additional modules: nf_conntrack_ftp nf_conntrack_tftp [ OK ] Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1181] device (ens3): Activation: starting connection 'System ens3' (db7b64ba-a781-4456-8a0f-9d41a8e8904b) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1185] device (ens3): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed') Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1281] manager: NetworkManager state is now CONNECTING Nov 8 15:57:36 localhost hostname.sh[948]: hostname: localhost.localdomain Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1332] device (ens3): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') Nov 8 15:57:36 localhost nm-dispatcher[931]: req:2 'connectivity-change': start running ordered scripts... Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1511] device (ens3): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1569] dhcp4 (ens3): activation: beginning transaction (timeout in 45 seconds) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.1660] dhcp4 (ens3): dhclient started with pid 953 Nov 8 15:57:36 localhost dhclient[953]: DHCPREQUEST for 192.168.4.3 on ens3 to 255.255.255.255 port 67 (xid=0x475a9242) Nov 8 15:57:36 localhost dhclient[953]: DHCPACK of 192.168.4.3 from 192.168.4.1 (xid=0x475a9242) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2685] dhcp4 (ens3): address 192.168.4.3 Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): plen 24 (255.255.255.0) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): gateway 192.168.4.1 Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): lease time 43200 Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): hostname 'mail' Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): nameserver '192.168.4.1' Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): domain name 'redfish-solutions.com' Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp (ens3): domain search 'redfish-solutions.com.' Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp (ens3): domain search 'redfish-consulting.com.' Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2689] dhcp4 (ens3): state changed unknown -> extended, address=192.168.4.3 Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2752] device (ens3): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed') Nov 8 15:57:36 localhost nm-dispatcher[931]: req:3 'pre-up' [ens3]: new request (0 scripts) Nov 8 15:57:36 localhost nm-dispatcher[931]: req:3 'pre-up' [ens3]: completed: no scripts Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2921] device (ens3): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed') Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2923] device (ens3): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed') Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2928] manager: NetworkManager state is now CONNECTED_LOCAL Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3059] manager: NetworkManager state is now CONNECTED_SITE Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3063] policy: set 'System ens3' (ens3) as default for IPv4 routing and DNS Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3070] policy: set-hostname: set hostname to 'mail' (from DHCPv4) Nov 8 15:57:36 localhost systemd-resolved[800]: ens3: Bus client set search domain list to: redfish-solutions.com, redfish-consulting.com Nov 8 15:57:36 localhost systemd-resolved[800]: ens3: Bus client set default route setting: yes Nov 8 15:57:36 localhost systemd-resolved[800]: ens3: Bus client set DNS server list to: 192.168.4.1 Nov 8 15:57:36 localhost dhclient[953]: bound to 192.168.4.3 -- renewal in 19936 seconds. Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3361] device (ens3): Activation: successful, device activated. Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3371] manager: NetworkManager state is now CONNECTED_GLOBAL Nov 8 15:57:36 localhost nm-dispatcher[931]: req:4 'up' [ens3]: new request (6 scripts) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3386] manager: startup complete Nov 8 15:57:36 localhost nm-dispatcher[931]: req:4 'up' [ens3]: start running ordered scripts... Nov 8 15:57:36 localhost nm-dispatcher[931]: req:5 'connectivity-change': new request (6 scripts) Nov 8 15:57:36 localhost nm-dispatcher[931]: req:6 'hostname': new request (6 scripts) Nov 8 15:57:36 localhost 11-dhclient[996]: Would have set domainname redfish-solutions.com Nov 8 15:57:36 localhost hostname.sh[1010]: up: mail.redfish-solutions.com Nov 8 15:57:36 localhost nm-dispatcher[931]: req:5 'connectivity-change': start running ordered scripts... Nov 8 15:57:36 localhost nm-dispatcher[931]: req:6 'hostname': start running ordered scripts... Nov 8 15:57:36 localhost hostname.sh[1040]: hostname: localhost.localdomain Nov 8 15:57:37 localhost httpd[985]: AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using localhost.localdomain. Set the 'ServerName' directive globally to suppress this message Nov 8 15:57:37 localhost httpd[985]: Server configured, listening on: port 443, port 80 Nov 8 15:57:37 localhost rsyslogd[854]: imjournal: journal files changed, reloading... [v8.2102.0-3.fc34 try https://www.rsyslog.com/e/0 ] Nov 8 15:57:39 localhost dbus-daemon[1306]: [session uid=1000 pid=1304] Activating service name='org.freedesktop.systemd1' requested by ':1.0' (uid=1000 pid=1307 comm="systemctl --user import-environment DISPLAY XAUTHO" label="system_u:system_r:unconfined_service_t:s0") Nov 8 15:57:39 localhost dbus-daemon[1306]: [session uid=1000 pid=1304] Activated service 'org.freedesktop.systemd1' failed: Process org.freedesktop.systemd1 exited with status 1 Nov 8 15:57:40 localhost check[898]: prefork: child states: II Nov 8 15:58:40 localhost systemd-logind[867]: New session 1 of user root. Nov 8 15:59:15 localhost setroubleshoot[1368]: SELinux is preventing systemd from remove_name access on the directory localhost.localdomain:2.pid. For complete SELinux messages run: sealert -l 92f33fbf-91c5-4950-a7b3-b42e8845cc68 Nov 8 15:59:15 localhost setroubleshoot[1368]: SELinux is preventing systemd from remove_name access on the directory localhost.localdomain:2.pid.#012#012***** Plugin catchall (100. confidence) suggests **************************#012#012If you believe that systemd should be allowed remove_name access on the localhost.localdomain:2.pid directory by default.#012Then you should report this as a bug.#012You can generate a local policy module to allow this access.#012Do#012allow this access for now by executing:#012# ausearch -c 'systemd' --raw | audit2allow -M my-systemd#012# semodule -X 300 -i my-systemd.pp#012 The lines that I find interesting are: Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8153] hostname: hostname: using hostnamed Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8155] hostname: hostname changed from (none) to "localhost.localdomain" ... Nov 8 15:57:35 localhost NetworkManager[821]: <info> [1636412255.8789] dhcp-init: Using DHCP client 'dhclient' ... Nov 8 15:57:35 localhost nm-dispatcher[931]: req:1 'hostname': new request (6 scripts) Nov 8 15:57:35 localhost nm-dispatcher[931]: req:1 'hostname': start running ordered scripts... ... Nov 8 15:57:36 localhost hostname.sh[948]: hostname: localhost.localdomain <<<<< from dispatcher.d/hostname.sh ... Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): hostname 'mail' ... Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.2686] dhcp4 (ens3): domain name 'redfish-solutions.com' ... Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3070] policy: set-hostname: set hostname to 'mail' (from DHCPv4) <<<<< should be set to what we want, right? but it's not... ... Nov 8 15:57:36 localhost dhclient[953]: bound to 192.168.4.3 -- renewal in 19936 seconds. ... Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3371] manager: NetworkManager state is now CONNECTED_GLOBAL Nov 8 15:57:36 localhost nm-dispatcher[931]: req:4 'up' [ens3]: new request (6 scripts) Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3386] manager: startup complete Nov 8 15:57:36 localhost nm-dispatcher[931]: req:4 'up' [ens3]: start running ordered scripts... Nov 8 15:57:36 localhost nm-dispatcher[931]: req:5 'connectivity-change': new request (6 scripts) Nov 8 15:57:36 localhost nm-dispatcher[931]: req:6 'hostname': new request (6 scripts) Nov 8 15:57:36 localhost hostname.sh[1010]: up: mail.redfish-solutions.com <<<<< from dispatcher.d/hostname.sh showing "${DHCP4_HOST_NAME}.${DHCP4_DOMAIN_NAME}" with correctly provisioned values from DHCP server Nov 8 15:57:36 localhost nm-dispatcher[931]: req:5 'connectivity-change': start running ordered scripts... Nov 8 15:57:36 localhost nm-dispatcher[931]: req:6 'hostname': start running ordered scripts... Nov 8 15:57:36 localhost hostname.sh[1040]: hostname: localhost.localdomain <<<<< from dispatcher.d/hostname.sh Those last 2 lines from /etc/NetworkManager/dispatcher.d/hostname.sh are what's interesting.
If I uncomment these lines: case "$ACTION" in ... up) log "up: ${DHCP4_HOST_NAME}.${DHCP4_DOMAIN_NAME}" # hostname "${DHCP4_HOST_NAME}" # domainname "${DHCP4_DOMAIN_NAME}" ;; esac then the system boots and functions correctly, but why is this site-specific localization even necessary? This is what's supposed to happen out-of-the-box, right? It tells me it's doing: Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3070] policy: set-hostname: set hostname to 'mail' (from DHCPv4) but it isn't actually. Also, what happens to option 15 (domain name)?
It does log the domain name too: Nov 8 15:57:36 localhost 11-dhclient[996]: Would have set domainname redfish-solutions.com that's coming from /usr/lib/NetworkManager/dispatcher.d/11-dhclient somehow, it looks like, though it must be from something it calls, as "Would have" doesn't appear in it anywhere. The message does imply that it "would have" set the domain from DHCP, but it didn't because...why? I'll note that NetworkManager.conf does suggest this should work, specifically in the section on hostname-mode: hostname-mode Set the management mode of the hostname. This parameter will affect only the transient hostname. If a valid static hostname is set, NetworkManager will skip the update of the hostname despite the value of this option. An hostname empty or equal to 'localhost', 'localhost6', 'localhost.localdomain' or 'localhost6.localdomain' is considered invalid. default: NetworkManager will update the hostname with the one provided via DHCP or reverse DNS lookup of the IP address on the connection with the default route or on any connection with the property hostname.only-from-default set to 'false'. Connections are considered in order of increasing value of the hostname.priority property. In case multiple connections have the same priority, connections activated earlier are considered first. If no hostname can be determined in such way, the hostname will be updated to the last one set outside NetworkManager or to 'localhost.localdomain'. dhcp: this is similar to 'default', with the difference that after trying to get the DHCP hostname, reverse DNS lookup is not done. Note that selecting this option is equivalent to setting the property 'hostname.from-dns-lookup' to 'false' globally for all connections in NetworkManager.conf. none: NetworkManager will not manage the transient hostname and will never set it. that suggests that in the 'default' mode it should override 'localhost.localdomain' (which it says is "considered invalid") with the hostname received via DHCP. So I'm not sure why it is not, in fact, doing that.
Sorry, I left out my script /etc/dhcp/dhclient.d/hostname.sh: #!/bin/bash PROG="$(basename "$0")" hostname_config() { domain_portion="$(echo "${new_host_name}" | cut -s -d. -f2-)" [ -z "${domain_portion}" ] || return [ -n "${new_domain_name}" ] || return # logger -p daemon.info -t "$PROG" "Setting domainname ${new_domain_name}" # domainname "${new_domain_name}" logger -p daemon.info -t "$PROG" "Would have set domainname ${new_domain_name}" } hostname_restore() { # nothing to do : }
Also, see https://github.com/NetworkManager/NetworkManager/blob/main/src/core/nm-policy.c#L634
What would cause this to fail and how could we confirm that it is? https://github.com/NetworkManager/NetworkManager/blob/main/src/core/nm-hostname-manager.c#L263
What is the output of 'hostnamectl' after the boot? Nov 8 15:57:36 localhost NetworkManager[821]: <info> [1636412256.3070] policy: set-hostname: set hostname to 'mail' (from DHCPv4) This message comes from here: https://gitlab.freedesktop.org/NetworkManager/NetworkManager/-/blob/1.30.6/src/core/nm-policy.c#L628 where nm_hostname_manager_set_transient_hostname() is called to update the hostname via systemd-hostnamed: https://gitlab.freedesktop.org/NetworkManager/NetworkManager/-/blob/1.30.6/src/core/nm-hostname-manager.c#L283-313 If the D-Bus call failed we should see an error message, so I presume that it succeeded. Perhaps you could monitor what happens on D-Bus with 'busctl monitor' (there should be a SetHostname call there).
hostnamectl says: Static hostname: localhost.localdomain Transient hostname: fedora Icon name: computer-vm Chassis: vm Machine ID: 96c3882a169d04a924b3447200000006 Boot ID: e8ab2d55411346438fbbd2c3326b3535 Virtualization: kvm Operating System: Fedora 34 (Thirty Four) CPE OS Name: cpe:/o:fedoraproject:fedora:34 Kernel: Linux 5.14.16-201.fc34.x86_64 Architecture: x86-64 Hardware Vendor: Red Hat Hardware Model: KVM Attaching "busctl monitor" output as well. I brought the machine up, logged into the console, did an "ifdown ifcfg-ens3", started the "busctl monitor > file &", ran "ifup ifcfg-ens3", then killed the "busctl".
Created attachment 1840929 [details] output from busctl monitor while interface was brought up Interesting part is here: ‣ Type=method_call Endian=l Flags=0 Version=1 Cookie=517 Timestamp="Tue 2021 -11-09 18:30:55.394682 UTC" Sender=:1.1 Destination=org.freedesktop.hostname1 Path=/org/freedesktop/hostname1 Interface=org.freedesktop.hostname1 Member=SetHostname UniqueName=:1.1 MESSAGE "sb" { STRING "mail"; BOOLEAN false; }; didn't see a response, unless this is it: ‣ Type=method_return Endian=l Flags=1 Version=1 Cookie=5 ReplyCookie=517 Timestamp="Tue 2021-11-09 18:30:55.533125 UTC" Sender=:1.39 Destination=:1.1 UniqueName=:1.39 MESSAGE "" { };
This message is a reminder that Fedora Linux 34 is nearing its end of life. Fedora will stop maintaining and issuing updates for Fedora Linux 34 on 2022-06-07. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a 'version' of '34'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, change the 'version' to a later Fedora Linux version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora Linux 34 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora Linux, you are encouraged to change the 'version' to a later version prior to this bug being closed.
Fedora Linux 34 entered end-of-life (EOL) status on 2022-06-07. Fedora Linux 34 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. Thank you for reporting this bug and we are sorry it could not be fixed.