Bug 983320

Summary: NetworkManager dhcp4 dispatcher script contains incorrect server identifier
Product: [Fedora] Fedora Reporter: Scott Shambarger <scott-fedora>
Component: NetworkManagerAssignee: Dan Williams <dcbw>
Status: CLOSED EOL QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 20CC: cra, dcbw, hvtaifwkbgefbaei
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-06-29 12:04:08 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Patch to re-order dhcp4 state update before dhcp4_lease_change none

Description Scott Shambarger 2013-07-11 00:31:09 UTC
Description of problem:
When NetworkManager receives a dhclient state change, the new server identifier is not included in the dispatcher script environment (the previous server identifier is used).

Version-Release number of selected component (if applicable):
NetworkManager-0.9.8.1-3.git20130514.fc18

How reproducible:
Whenever a dhcp4-change results in a new dhcp server

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. When dhclient renews the lease, examine the environment of the dispatcher

Actual results:
Server identifier is not correct.  The server identifier (and router) is from the previous bind.

Expected results:
The server identifier should be the same as the dhclient script retrieved.

Additional info:
I have a Comcast modem.  When the coax cable is disconnected, 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 from the remote server.

From the logs:
Jul 10 16:16:23 dhclient[12533]: bound to 192.168.100.10 -- renewal in 10 seconds.
Jul 10 16:16:23 NetworkManager[546]: <info> (em1): DHCPv4 state changed bound -> renew
Jul 10 16:16:23 NetworkManager[546]: <info>   address 192.168.100.10
Jul 10 16:16:23 NetworkManager[546]: <info>   prefix 24 (255.255.255.0)
Jul 10 16:16:23 NetworkManager[546]: <info>   gateway 192.168.100.1
...
Jul 10 16:16:41 dhclient[12533]: bound to 76.102.27.32 -- renewal in 117479 seconds.
Jul 10 16:16:41 NetworkManager[546]: <info> (em1): DHCPv4 state changed preinit -> bound
Jul 10 16:16:41 NetworkManager[546]: <info>   address 76.102.27.32
Jul 10 16:16:41 NetworkManager[546]: <info>   prefix 23 (255.255.254.0)
Jul 10 16:16:41 NetworkManager[546]: <info>   gateway 76.102.27.1
Jul 10 16:16:41 NetworkManager[546]: <info>   nameserver '75.75.75.75'
Jul 10 16:16:41 NetworkManager[546]: <info>   nameserver '75.75.76.76'

Capturing the (abbreviated) environment from the dispatcher (with a file in /etc/NetworkManager/dispatcher.d) results in the following:

Wed Jul 10 16:16:23 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

Wed Jul 10 16:16:43 PDT 2013
IP4_NUM_ADDRESSES=1
IP4_ADDRESS_0=76.102.26.32/23 76.102.26.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 not correctly updated.

This makes it impossible to correctly identify the DHCP server from the dispatch scripts... and in my case, correctly add the firewall rule to allow packets to reach the DHCP server in a multi-homed network setup (which should be automatic, but that's another bug :)

Comment 1 Scott Shambarger 2013-07-11 00:43:46 UTC
Forgot to add all the relevant logs to the above report:

Jul 10 16:16:23 dhclient[12533]: DHCPREQUEST on em1 to 192.168.100.1 port 67 (xid=0x51101039)
Jul 10 16:16:23 dhclient[12533]: DHCPACK from 192.168.100.1 (xid=0x51101039)

Jul 10 16:16:33 dhclient[12533]: DHCPREQUEST on em1 to 192.168.100.1 port 67 (xid=0x51101039)
Jul 10 16:16:41 dhclient[12533]: DHCPREQUEST on em1 to 255.255.255.255 port 67 (xid=0x51101039)
Jul 10 16:16:41 dhclient[12533]: DHCPNAK from 96.147.132.1 (xid=0x51101039)
Jul 10 16:16:41 NetworkManager[546]: <info> (em1): DHCPv4 state changed renew -> expire
Jul 10 16:16:41 dhclient[12533]: DHCPDISCOVER on em1 to 255.255.255.255 port 67 interval 8 (xid=0x255b9617)
Jul 10 16:16:41 NetworkManager[546]: <info> (em1): DHCPv4 state changed expire -> preinit
Jul 10 16:16:41 dhclient[12533]: DHCPREQUEST on em1 to 255.255.255.255 port 67 (xid=0x255b9617)
Jul 10 16:16:41 dhclient[12533]: DHCPOFFER from 96.147.132.1
Jul 10 16:16:41 dhclient[12533]: DHCPACK from 96.147.132.1 (xid=0x255b9617)

Comment 2 Fedora End Of Life 2013-12-21 14:18:04 UTC
This message is a reminder that Fedora 18 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 18. 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 WONTFIX if it remains open with a Fedora 
'version' of '18'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 18's end of life.

Thank you for reporting this issue and we are sorry that we may not be 
able to fix it before Fedora 18 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, you are encouraged  change the 'version' to a later Fedora 
version prior to Fedora 18's end of life.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 3 Scott Shambarger 2013-12-24 01:13:20 UTC
Re-tested with NetworkManager-0.9.9.0-22.git20131003.fc20 and still received a stale server identifier in the dispatcher.

Moving to F20

Comment 4 Scott Shambarger 2013-12-24 03:15:01 UTC
BTW, I've logged an upstream bug on bugzilla.gnome.org:
Bug 721002 -  NM dispatcher script DHCP4_ environment variables stale on bound after expire

Comment 5 Scott Shambarger 2014-01-06 15:17:54 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.

Applied to NetworkManager-0.9.9.0-22.git20131003 and tested, and the change does indeed fix the problem.

I'll attach the patch, and see if I can create one for the upstream bug I filed too.

Comment 6 Scott Shambarger 2014-01-06 15:19:11 UTC
Created attachment 846144 [details]
Patch to re-order dhcp4 state update before dhcp4_lease_change

Comment 7 Scott Shambarger 2014-01-06 16:02:25 UTC
Attached patch to upstream bug and sent to networkmanager-list.

Comment 8 Scott Shambarger 2014-01-07 17:23:09 UTC
BTW, not sure if it's important, but for consistency perhaps the DHCP notifies should be sent before the IP notifies in notify_ip_properties()? (since DHCP would normally be expected to be updated before the ip settings?)

Comment 9 Sami Farin 2014-05-03 21:34:11 UTC
broken in 0.9.9.0-38.git20131003.fc20.

# cat /etc/NetworkManager/dispatcher.d/19-showenv 
#!/bin/bash
env > /etc/dhcp/nm-showenv-"${1}"-"${2}".txt
# pcregrep "192\.168\.1\.10\d" /etc/dhcp/nm-showenv-eno1-dhcp4-change.txt
IP4_ADDRESS_0=192.168.1.101/24 192.168.1.1
DHCP4_IP_ADDRESS=192.168.1.102
# l /etc/dhcp/nm-showenv-eno1-dhcp4-change.txt
-rw-r--r-- 1 root root 1354 2014-05-04 00:14:43.043124400 +0300 /etc/dhcp/nm-showenv-eno1-dhcp4-change.txt

May  4 00:14:42 localhost dhclient[4462]: bound to 192.168.1.101 -- renewal in 41198 seconds.

Comment 10 Scott Shambarger 2014-05-04 19:57:14 UTC
Comment 9 appears to be an unrelated bug... the server identifier is the dhcp server address, the "bound to" link is the client's assigned address.

Might want to file a new bug.

Comment 11 Fedora End Of Life 2015-05-29 09:10:18 UTC
This message is a reminder that Fedora 20 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 20. 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 Fedora  'version'
of '20'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 20 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, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 12 Fedora End Of Life 2015-06-29 12:04:08 UTC
Fedora 20 changed to end-of-life (EOL) status on 2015-06-23. Fedora 20 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. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.