After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 721002 - NM dispatcher script DHCP4_ environment variables stale on bound after expire
NM dispatcher script DHCP4_ environment variables stale on bound after expire
Status: RESOLVED FIXED
Product: NetworkManager
Classification: Platform
Component: IP and DNS config
unspecified
Other Linux
: Normal normal
: ---
Assigned To: NetworkManager maintainer(s)
NetworkManager maintainer(s)
Depends on:
Blocks:
 
 
Reported: 2013-12-24 03:13 UTC by Scott Shambarger
Modified: 2014-01-06 22:06 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Patch to re-order dhcp4 state update before dhcp4_lease_change (1.07 KB, patch)
2014-01-06 15:55 UTC, Scott Shambarger
none Details | Review

Description Scott Shambarger 2013-12-24 03:13:05 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 :).
Comment 1 Scott Shambarger 2014-01-06 15:55:17 UTC
Created attachment 265450 [details] [review]
 Patch to re-order dhcp4 state update before dhcp4_lease_change
Comment 2 Scott Shambarger 2014-01-06 15:57:09 UTC
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).
Comment 3 Dan Williams 2014-01-06 22:06:37 UTC
Thanks!  I've also made the same fix to the DHCPv6 code.