GNOME Bugzilla – Bug 721002
NM dispatcher script DHCP4_ environment variables stale on bound after expire
Last modified: 2014-01-06 22:06:37 UTC
I'm filing this as an upstream version of redhat bug 983320.. Description of problem: When NetworkManager initiates a expire->preinit->bound dhcp state change, the dispatcher scripts are given stale DHCP4_* values. Version-Release number of selected component (if applicable): NetworkManager-0.9.9.0-22.git20131003.fc20 Steps to Reproduce: 1. Setup NetworkManager on an interface with BOOTPROTO=dhcp 2. Allow dhcp to configure interface 3. Change the dhcpd server identifier 4. Allow the dhcp lease to expire and allow dhclient to acquire a new lease. Results: Server identifier is not correct. The server identifier and all DHCP4_ values are from the previous bind. Additional info: I have a Comcast modem. When the coax cable is disconnected/fails, the modem will provide a non-routable address from the 192.168.100.[1-254] pool, and a server identifier of 192.168.100.1 Once the coax is reattached (or the cable system comes back online), a globally routable address is provided, along with a server identifier. Abbreviated log entries: Dec 23 16:31:42 shambarger dhclient[28343]: bound to 192.168.100.10 -- renewal in 10 seconds. Dec 23 16:31:42 shambarger NetworkManager[645]: <info> (p17p2): DHCPv4 state changed renew -> renew Dec 23 16:31:42 shambarger NetworkManager[645]: <info> address 192.168.100.10 Dec 23 16:31:42 shambarger NetworkManager[645]: <info> plen 24 (255.255.255.0) Dec 23 16:31:42 shambarger NetworkManager[645]: <info> gateway 192.168.100.1 Dec 23 16:31:42 shambarger NetworkManager: bound to 192.168.100.10 -- renewal in 10 seconds. Dec 23 16:31:58 shambarger dhclient[28343]: DHCPREQUEST on p17p2 to 192.168.100.1 port 67 (xid=0xb869b7d) Dec 23 16:31:58 shambarger NetworkManager: DHCPREQUEST on p17p2 to 192.168.100.1 port 67 (xid=0xb869b7d) Dec 23 16:32:03 shambarger NetworkManager[645]: <info> (p17p2): DHCPv4 state changed renew -> expire Dec 23 16:32:03 shambarger NetworkManager[645]: <info> (p17p2): DHCPv4 state changed expire -> preinit Dec 23 16:32:03 shambarger dhclient[28343]: DHCPDISCOVER on p17p2 to 255.255.255.255 port 67 interval 7 (xid=0x7 9da836) Dec 23 16:32:03 shambarger NetworkManager: DHCPDISCOVER on p17p2 to 255.255.255.255 port 67 interval 7 (xid=0x79da836) Dec 23 16:32:03 shambarger dhclient[28343]: DHCPREQUEST on p17p2 to 255.255.255.255 port 67 (xid=0x79da836) Dec 23 16:32:03 shambarger dhclient[28343]: DHCPOFFER from 96.120.89.249 Dec 23 16:32:03 shambarger NetworkManager: DHCPREQUEST on p17p2 to 255.255.255.255 port 67 (xid=0x79da836) Dec 23 16:32:03 shambarger NetworkManager: DHCPOFFER from 96.120.89.249 Dec 23 16:32:03 shambarger dhclient[28343]: DHCPACK from 96.120.89.249 (xid=0x79da836) Dec 23 16:32:03 shambarger NetworkManager: DHCPACK from 96.120.89.249 (xid=0x79da836) Dec 23 16:32:03 shambarger dhclient[28343]: bound to 76.126.201.59 -- renewal in 105775 seconds. Dec 23 16:32:03 shambarger NetworkManager[645]: <info> (p17p2): DHCPv4 state changed preinit -> bound Dec 23 16:32:03 shambarger NetworkManager[645]: <info> address 76.126.201.89 Dec 23 16:32:03 shambarger NetworkManager[645]: <info> plen 21 (255.255.248.0) Dec 23 16:32:03 shambarger NetworkManager[645]: <info> gateway 76.126.200.1 Dec 23 16:32:03 shambarger NetworkManager: bound to 76.126.201.59 -- renewal in 105775 seconds. Capturing the (abbreviated) environment from the dispatcher (with a file in /etc/NetworkManager/dispatcher.d) results in the following: Dec 23 16:31:42 PDT 2013 IP4_NUM_ADDRESSES=1 IP4_ADDRESS_0=192.168.100.10/24 192.168.100.1 DHCP4_DHCP_SERVER_IDENTIFIER=192.168.100.1 DHCP4_BROADCAST_ADDRESS=192.168.100.255 DHCP4_IP_ADDRESS=192.168.100.10 DHCP4_ROUTERS=192.168.100.1 Dec 23 16:32:03 PDT 2013 IP4_NUM_ADDRESSES=1 IP4_ADDRESS_0=76.126.201.89/21 76.126.200.1 DHCP4_DHCP_SERVER_IDENTIFIER=192.168.100.1 DHCP4_BROADCAST_ADDRESS=192.168.100.255 DHCP4_IP_ADDRESS=192.168.100.10 DHCP4_ROUTERS=192.168.100.1 The IP4_* environment correctly reflects the updated dhclient information, but the DHCP4_* environment is stale. If I query the device from nmcli within the dispatcher script, the values returned are correct... eg: /bin/nmcli device show p17p2 | /bin/awk '/DHCP4\.OPTION.*dhcp_server_identifier/ { print $4 }' 69.252.97.6 I'd trace the source of the stale data myself, but I haven't found a good explanation of how different parts of NM pass state around. If there's a debug setting that would provide more detail you could use, let me know and I'll provide the trace. BTW, I need the server identifier in order to provide a routing entry for the server, as NM isn't adding a routing entry for it... I've logged that as redhat bug 983325, and I may create an upstream bug for that too :).
Created attachment 265450 [details] [review] Patch to re-order dhcp4 state update before dhcp4_lease_change
Tracked the problem down to nm-device.c... when the dhcp configuration is updated, the dispatcher is triggered before the dhcp4 state has been updated. I've attached a patch to re-orders the dhcp4 state change to before the call to dhcp4_lease_change. Attached patch... testing on the redhat build shows it fixes the problem, I haven't tested the patch against git master though (tough to test on Fedora).
Thanks! I've also made the same fix to the DHCPv6 code.