#459813 dhclient unnecessarily brings down interface on lease renew

Package:
isc-dhcp-client
Source:
isc-dhcp
Description:
DHCP client for automatically obtaining an IP address
Submitter:
martin f krafft
Date:
2015-09-05 20:48:22 UTC
Severity:
important
#459813#3
Date:
2008-01-08 21:13:16 UTC
From:
To:
When dhclient renewed a lease, it *should* call dhclient-script with
RENEW. If it failed, it *should* call the script with EXPIRE.

However, dhclient calls the script with EXPIRE as soon as the lease
expires, issues a PREINIT, and *then* seeks to renew the lease and
issues a BOUND event when successful. This is quite stupid as the
machine goes offline for a second, and it's also not what the
manpages says:

       The  DHCP  client  has  failed  to  renew  its  lease or
       acquire a new one, and the lease has expired.   The IP
       address must be relinquished, and all related parameters
       should be deleted, as in RENEW and REBIND.

I noticed this while developing netconf. Look at its debug output
during a normal renew:

dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['old_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: received pair: ['old_expiry', '1199826651']
dhclientProxy_eth0: DEBUG: received pair: ['old_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['old_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['old_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'EXPIRE']
dhclientProxy_eth0: DEBUG: received pair: ['old_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got EXPIRE/FAIL: removing address from interface eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=132 type=IPADDR completed=0 params={'ACTION': 'delete', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: DEBUG: received event: <Event id=132 type=IPADDR completed=0 params={'ACTION': 'delete', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: INFO: deleting addresses on interface eth0: inet 192.168.14.125/25
MainThread: DEBUG: received SIGCHLD
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'PREINIT']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got PREINIT: upping interface eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=133 type=IPLINK completed=0 params={'LINK_STATE': 'up', 'IFACE': 'eth0'}>
MainThread: DEBUG: received event: <Event id=133 type=IPLINK completed=0 params={'LINK_STATE': 'up', 'IFACE': 'eth0'}>
MainThread: INFO: bringing interface eth0 up
MainThread: DEBUG: received SIGCHLD
dhclientProxy_eth0: DEBUG: received pair: ['new_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: received pair: ['old_expiry', '1199826651']
dhclientProxy_eth0: DEBUG: received pair: ['new_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['new_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['old_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['new_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['new_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: received pair: ['old_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['new_expiry', '1199826682']
dhclientProxy_eth0: DEBUG: received pair: ['old_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['new_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['old_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['old_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'BOUND']
dhclientProxy_eth0: DEBUG: received pair: ['old_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['old_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got BOUND/REBOOT: configuring interface %s eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=134 type=IPADDR completed=0 params={'ACTION': 'set', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: DEBUG: received event: <Event id=134 type=IPADDR completed=0 params={'ACTION': 'set', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: INFO: seting addresses on interface eth0: inet 192.168.14.125/25
MainThread: DEBUG: received SIGCHLD
#459813#6
Date:
2008-01-09 16:29:52 UTC
From:
To:
So it seems that this is hard to reproduce and I am still not sure
what's going on. Attached is a pcap file of a couple of dialogues
with a 15s expiry time.

Note how packet 5 is a request that goes unanswered, which would
explain the EXPIRE and subsequent discovery. I cannot say why the
request goes unanswered. The server actually sees the requests and
ACKs:

dhcpd: DHCPREQUEST for 192.168.14.28 from 4e:80:ba:7e:34:14 via lan
dhcpd: DHCPACK on 192.168.14.28 to 4e:80:ba:7e:34:14 via lan
dhcpd: DHCPDISCOVER from 4e:80:ba:7e:34:14 via lan
dhcpd: DHCPOFFER on 192.168.14.28 to 4e:80:ba:7e:34:14 via lan
dhcpd: DHCPREQUEST for 192.168.14.28 (192.168.14.1) from 4e:80:ba:7e:34:14 via lan
dhcpd: DHCPACK on 192.168.14.28 to 4e:80:ba:7e:34:14 via lan

but the ACK apparently doesn't make it to the client. My network is
otherwise fully functional, however.

Anyway, what is also strange is that after packet 9 (the final ACK
of the second transaction), the client just sends a DISCOVER without
a REQUEST.

Something's fishy...
#459813#11
Date:
2008-01-15 04:28:36 UTC
From:
To:
Would you mind trialing the 3.1.0-1 version that I uploaded to unstable
yesterday? I've been doing some testing along the lines of your blog post,
and I can't see anything untoward yet, but it's a bit early to say for sure.

regards

Andrew
#459813#16
Date:
2008-08-02 22:22:07 UTC
From:
To:
also sprach Andrew Pollock <apollock@debian.org> [2008.01.15.0228 -0200]:

I can reproduce this with 3.1.1-3 and also don't need netconf
anymore... just a normal 'dhclient eth0' invocation will make it
happen.
#459813#21
Date:
2008-08-06 19:24:44 UTC
From:
To:
  The ignored DHCPACK packets look very much like a defect I have been
looking at recently.

  I have seen multiple DHCPREQUEST packets coming from dhclient 3.1.1-3,
(and other versions).  They keep repeating from the RENEW timeout
until the REBIND timeout.  I tracked down the cause in one system
running dhclient 3.1.1-3.  The problem occured when DHCPACK packets are
consumed by a second dhclient process that is supposed to be handling a
different NIC.  All of the dhclient processes are reading from sockets
that are bound to UDP port 68 and address 0.0.0.0.  The sockets have no
association with a particular NIC or IP.  There is a race to determine
which process will read each DHCPACK packet.  And it is very common for
one of the other dhclient processes to read and discard every DHCPACK
intended for a particular dhclient handling a particular NIC.

  This problem could be avoided by having a single dhclient handling
all of the NICs.  But the trend has been toward having one dhclient per
NIC for flexible handling of NICs that are enabled after dhclient is
started.  If there will be multiple dhclient processes then they will
need to start sharing the data that they read from their port 68 sockets.
#459813#26
Date:
2010-07-11 17:01:16 UTC
From:
To:
Hi,

This bug was reported to us some time ago.

Mike Stroyan has an update at
http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=459813#21, which suggests
what the problem may be (architectural).

The entire bug history is at
http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=459813

Please maintain the Cc in any replies to keep our bug tracking system in the
loop.

regards

Andrew

----- Forwarded message from martin f krafft <madduck@debian.org> -----

Subject: Bug#459813: dhclient unnecessarily brings down interface on lease renew
Reply-To: martin f krafft <madduck@debian.org>, 459813@bugs.debian.org
Resent-From: martin f krafft <madduck@debian.org>
Resent-To: debian-bugs-dist@lists.debian.org
Resent-CC: peloy@debian.org (Eloy A. Paris)
Resent-Date: Tue, 08 Jan 2008 21:15:04 +0000
Resent-Message-ID: <handler.459813.B.11998268025082@bugs.debian.org>
Resent-Sender: owner@bugs.debian.org
X-Debian-PR-Message: report 459813
X-Debian-PR-Package: dhcp3-client
X-Debian-PR-Keywords:
X-Debian-PR-Source: dhcp3
X-Spam-Checker-Version: SpamAssassin 3.1.4-bugs.debian.org_2005_01_02
	(2006-07-26) on rietz.debian.org
X-Spam-Level:
X-Spam-Status: No, score=-13.5 required=4.0 tests=BAYES_00,FORGED_RCVD_HELO,
	FOURLA,FROMDEVELOPER,HAS_PACKAGE,INFO_TLD,X_DEBBUGS_NO_ACK
	autolearn=no version=3.1.4-bugs.debian.org_2005_01_02
From: martin f krafft <madduck@debian.org>
To: Debian Bug Tracking System <submit@bugs.debian.org>
X-Reportbug-Version: 3.39
X-Virus-Scanned: ClamAV 0.92/5443/Tue Jan  8 18:35:47 2008 on seamus.madduck.net
X-Virus-Status: Clean

Package: dhcp3-client
Version: 3.0.6.dfsg-1
Severity: important

When dhclient renewed a lease, it *should* call dhclient-script with
RENEW. If it failed, it *should* call the script with EXPIRE.

However, dhclient calls the script with EXPIRE as soon as the lease
expires, issues a PREINIT, and *then* seeks to renew the lease and
issues a BOUND event when successful. This is quite stupid as the
machine goes offline for a second, and it's also not what the
manpages says:

       The  DHCP  client  has  failed  to  renew  its  lease or
       acquire a new one, and the lease has expired.   The IP
       address must be relinquished, and all related parameters
       should be deleted, as in RENEW and REBIND.

I noticed this while developing netconf. Look at its debug output
during a normal renew:

dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['old_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: received pair: ['old_expiry', '1199826651']
dhclientProxy_eth0: DEBUG: received pair: ['old_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['old_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['old_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'EXPIRE']
dhclientProxy_eth0: DEBUG: received pair: ['old_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got EXPIRE/FAIL: removing address from interface eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=132 type=IPADDR completed=0 params={'ACTION': 'delete', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: DEBUG: received event: <Event id=132 type=IPADDR completed=0 params={'ACTION': 'delete', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: INFO: deleting addresses on interface eth0: inet 192.168.14.125/25
MainThread: DEBUG: received SIGCHLD
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'PREINIT']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got PREINIT: upping interface eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=133 type=IPLINK completed=0 params={'LINK_STATE': 'up', 'IFACE': 'eth0'}>
MainThread: DEBUG: received event: <Event id=133 type=IPLINK completed=0 params={'LINK_STATE': 'up', 'IFACE': 'eth0'}>
MainThread: INFO: bringing interface eth0 up
MainThread: DEBUG: received SIGCHLD
dhclientProxy_eth0: DEBUG: received pair: ['new_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: received pair: ['old_expiry', '1199826651']
dhclientProxy_eth0: DEBUG: received pair: ['new_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['new_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['old_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['new_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['new_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: received pair: ['old_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['new_expiry', '1199826682']
dhclientProxy_eth0: DEBUG: received pair: ['old_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['new_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['old_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['old_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'BOUND']
dhclientProxy_eth0: DEBUG: received pair: ['old_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['old_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got BOUND/REBOOT: configuring interface %s eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=134 type=IPADDR completed=0 params={'ACTION': 'set', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: DEBUG: received event: <Event id=134 type=IPADDR completed=0 params={'ACTION': 'set', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: INFO: seting addresses on interface eth0: inet 192.168.14.125/25
MainThread: DEBUG: received SIGCHLD



----- End forwarded message -----
#459813#29
Date:
2010-07-11 17:01:16 UTC
From:
To:
Hi,

This bug was reported to us some time ago.

Mike Stroyan has an update at
http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=459813#21, which suggests
what the problem may be (architectural).

The entire bug history is at
http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=459813

Please maintain the Cc in any replies to keep our bug tracking system in the
loop.

regards

Andrew

----- Forwarded message from martin f krafft <madduck@debian.org> -----

Subject: Bug#459813: dhclient unnecessarily brings down interface on lease renew
Reply-To: martin f krafft <madduck@debian.org>, 459813@bugs.debian.org
Resent-From: martin f krafft <madduck@debian.org>
Resent-To: debian-bugs-dist@lists.debian.org
Resent-CC: peloy@debian.org (Eloy A. Paris)
Resent-Date: Tue, 08 Jan 2008 21:15:04 +0000
Resent-Message-ID: <handler.459813.B.11998268025082@bugs.debian.org>
Resent-Sender: owner@bugs.debian.org
X-Debian-PR-Message: report 459813
X-Debian-PR-Package: dhcp3-client
X-Debian-PR-Keywords:
X-Debian-PR-Source: dhcp3
X-Spam-Checker-Version: SpamAssassin 3.1.4-bugs.debian.org_2005_01_02
	(2006-07-26) on rietz.debian.org
X-Spam-Level:
X-Spam-Status: No, score=-13.5 required=4.0 tests=BAYES_00,FORGED_RCVD_HELO,
	FOURLA,FROMDEVELOPER,HAS_PACKAGE,INFO_TLD,X_DEBBUGS_NO_ACK
	autolearn=no version=3.1.4-bugs.debian.org_2005_01_02
From: martin f krafft <madduck@debian.org>
To: Debian Bug Tracking System <submit@bugs.debian.org>
X-Reportbug-Version: 3.39
X-Virus-Scanned: ClamAV 0.92/5443/Tue Jan  8 18:35:47 2008 on seamus.madduck.net
X-Virus-Status: Clean

Package: dhcp3-client
Version: 3.0.6.dfsg-1
Severity: important

When dhclient renewed a lease, it *should* call dhclient-script with
RENEW. If it failed, it *should* call the script with EXPIRE.

However, dhclient calls the script with EXPIRE as soon as the lease
expires, issues a PREINIT, and *then* seeks to renew the lease and
issues a BOUND event when successful. This is quite stupid as the
machine goes offline for a second, and it's also not what the
manpages says:

       The  DHCP  client  has  failed  to  renew  its  lease or
       acquire a new one, and the lease has expired.   The IP
       address must be relinquished, and all related parameters
       should be deleted, as in RENEW and REBIND.

I noticed this while developing netconf. Look at its debug output
during a normal renew:

dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['old_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: received pair: ['old_expiry', '1199826651']
dhclientProxy_eth0: DEBUG: received pair: ['old_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['old_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['old_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'EXPIRE']
dhclientProxy_eth0: DEBUG: received pair: ['old_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got EXPIRE/FAIL: removing address from interface eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=132 type=IPADDR completed=0 params={'ACTION': 'delete', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: DEBUG: received event: <Event id=132 type=IPADDR completed=0 params={'ACTION': 'delete', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: INFO: deleting addresses on interface eth0: inet 192.168.14.125/25
MainThread: DEBUG: received SIGCHLD
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'PREINIT']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got PREINIT: upping interface eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=133 type=IPLINK completed=0 params={'LINK_STATE': 'up', 'IFACE': 'eth0'}>
MainThread: DEBUG: received event: <Event id=133 type=IPLINK completed=0 params={'LINK_STATE': 'up', 'IFACE': 'eth0'}>
MainThread: INFO: bringing interface eth0 up
MainThread: DEBUG: received SIGCHLD
dhclientProxy_eth0: DEBUG: received pair: ['new_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['pid', '3106']
dhclientProxy_eth0: DEBUG: received pair: ['old_expiry', '1199826651']
dhclientProxy_eth0: DEBUG: received pair: ['new_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['new_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['PATH', '/usr/ucb:/usr/bin:/usr/sbin:/bin:/sbin']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['old_filename', '/debian-installer/i386/pxelinux.0']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['new_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_dhcp_message_type', '5']
dhclientProxy_eth0: DEBUG: received pair: ['new_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['new_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: received pair: ['old_netbios_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_lease_time', '30']
dhclientProxy_eth0: DEBUG: received pair: ['new_expiry', '1199826682']
dhclientProxy_eth0: DEBUG: received pair: ['old_broadcast_address', '192.168.14.127']
dhclientProxy_eth0: DEBUG: received pair: ['new_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['old_routers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['interface', 'eth0']
dhclientProxy_eth0: DEBUG: received pair: ['old_network_number', '192.168.14.0']
dhclientProxy_eth0: DEBUG: received pair: ['old_dhcp_server_identifier', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['reason', 'BOUND']
dhclientProxy_eth0: DEBUG: received pair: ['old_subnet_mask', '255.255.255.128']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name_servers', '192.168.14.1']
dhclientProxy_eth0: DEBUG: received pair: ['old_domain_name', 'stranger.oerlikon.madduck.net']
dhclientProxy_eth0: DEBUG: received pair: ['old_ip_address', '192.168.14.125']
dhclientProxy_eth0: DEBUG: processing data received from dhclient...
dhclientProxy_eth0: INFO: got BOUND/REBOOT: configuring interface %s eth0
dhclientProxy_eth0: DEBUG: queueing event: <Event id=134 type=IPADDR completed=0 params={'ACTION': 'set', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: DEBUG: received event: <Event id=134 type=IPADDR completed=0 params={'ACTION': 'set', 'PREFIXLEN': '255.255.255.128', 'IFACE': 'eth0', 'ADDRFAMILY': 'inet', 'ADDRESS': '192.168.14.125'}>
MainThread: INFO: seting addresses on interface eth0: inet 192.168.14.125/25
MainThread: DEBUG: received SIGCHLD



----- End forwarded message -----
#459813#32
Date:
2010-07-13 21:22:07 UTC
From:
To:
The DHCP software uses a common library for socket handling code. Because of
RFC 2131 requirements for the ability to receive 'directed unicasts' to
unconfigured addresses (without ARP), and also for platform agnostic support
for the all-ones limited broadcast address (255.255.255.255), we use a raw
socket on a interface-by-interface basis in order to receive DHCP messages.
This socket receives all DHCP packets for that interface, and is used to
transmit all "strange" directed unicasts, broadcasts, etc.

All DHCP software in the package - dhclient dhcrelay dhcpd - therefore has the
limitation that it will only receive packets physically received on the
interface it is configured to handle. If the packet is received on any other
interface, it is not read by an open raw socket by the DHCP software and
therefore isn't received.

The standard BSD socket on UDP ports 67/68 opened by these same pieces of
software is used for outbound unicast transmission only. We call it "the
fallback interface." This socket allows us to send UDP queries or replies in
unicast, using IP routing or ARP, without having to implement both of those
features over our existing raw socket. But: Any packet received on this BSD
socket is discarded. In future I intend to examine if we can set the socket
receive buffer size to zero to eliminate the extra read overhead, but I am
getting sidetracked.

Consequently, if the client configuring "intf0" is replied to by a DHCP server
that by unicast directs its reply to the client by first routing it to "intf1",
our client will be unable to see the reply. It will continue to attempt to
retransmit its renewal until REBINDING time. At REBINDING time, the client
switches to the raw socket as a limited broadcast on the connected interface -
this packet is picked up by a relay agent and the reply from the DHCP server is
directed through the relay agent, thus again reaching the raw socket on the
client's interface.

This is the only scenario I can imagine the described behavior happening.
Please advise if this doesn't sound familiar at all. Sorry for this known
limitation in our DHCP client software, as well as the other corner cases that
aren't well supported in our DHCP software suite. I hope to consider all of
these corner cases in the manufacture of our new IO system in BIND 10's DHCP
software (hopefully also eliminating the need for long-term raw sockets).

I'm not certain without examining software if switching to a single client
governing both interfaces actually will resolve the issue (I don't know if we
take the source interface structure into account when searching xid's for
matching DHCP state sessions). I think it is probable that using a single
dhclient is an effective workaround.


Note that this can change significantly if the client is built with USE_SOCKETS
instead of USE_LPF. But in this case the client is also incompatible with
Windows DHCP server. So I presume USE_LPF is in use.

Note also that the DHCPv6 software does not have this limitation owing to
multiple reasons, but primarily thanks to link-local addressing it does not
need or use raw sockets.