port-i386/49167: dhcpd drop lease and connection repeatedly used with a fxp interface

To: port-i386-maintainer%netbsd.org@localhost,gnats-admin%netbsd.org@localhost,netbsd-bugs%netbsd.org@localhost
Subject: port-i386/49167: dhcpd drop lease and connection repeatedly used with a fxp interface
From: adrian.christiansen%gmail.com@localhost
Date: Sun, 31 Aug 2014 12:05:00 +0000 (UTC)
>Number:         49167
>Category:       port-i386
>Synopsis:       dhcpd drop lease and connection repeatedly used with a fxp 
>interface
>Confidential:   no
>Severity:       serious
>Priority:       high
>Responsible:    port-i386-maintainer
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Aug 31 12:05:00 +0000 2014
>Originator:     Adrian Christiansen
>Release:        6.1.4
>Organization:
>Environment:
NetBSD farnsworth.hemma 6.1.4 NetBSD 6.1.4 (GENERIC) i386

IBM Thinkpad T23 type 2647
>Description:
dhpcd will acquire an IP and assign it to the fxp interface, then it will 
promptly drop the carrier and the lease. After this it will be stuck doing this 
in a loop.


fxp0 interface as listed by dmesg:

fxp0 at pci2 dev 8 function 0: Intel PRO/100 VE Network Controller (rev. 0x41)
fxp0: interrupting at irq 11
fxp0: Ethernet address 00:d0:59:b8:17:9a
inphy0 at fxp0 phy 1: i82562ET 10/100 media interface, rev. 0
inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto

Output from dhcpd in /var/messages, running /etc/rc.d/network start and later 
stop:

Aug 31 09:27:58 farnsworth dhcpcd[8038]: version 5.6.2 starting
Aug 31 09:27:58 farnsworth dhcpcd[8038]: fxp0: carrier acquired
Aug 31 09:27:58 farnsworth dhcpcd[8038]: fxp0: carrier lost
Aug 31 09:27:58 farnsworth dhcpcd[8038]: fxp0: waiting for carrier
Aug 31 09:28:00 farnsworth dhcpcd[8038]: fxp0: carrier acquired
Aug 31 09:28:00 farnsworth dhcpcd[8038]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:00 farnsworth dhcpcd[8038]: fxp0: broadcasting for a lease
Aug 31 09:28:01 farnsworth dhcpcd[8038]: fxp0: offered 192.168.1.53 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 09:28:01 farnsworth dhcpcd[8038]: fxp0: acknowledged 192.168.1.53 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 09:28:01 farnsworth dhcpcd[8038]: fxp0: checking for 192.168.1.53
Aug 31 09:28:03 farnsworth ntpd_intres[783]: parent died before we finished, 
exiting
Aug 31 09:28:04 farnsworth dhcpcd[8038]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:07 farnsworth dhcpcd[8038]: fxp0: leased 192.168.1.53 for 3600000 
seconds
Aug 31 09:28:07 farnsworth dhcpcd[8038]: forked to background, child pid 14138
Aug 31 09:28:07 farnsworth dhcpcd[14138]: fxp0: carrier lost
Aug 31 09:28:09 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:12 farnsworth dhcpcd[14138]: fxp0: carrier acquired
Aug 31 09:28:12 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:12 farnsworth dhcpcd[14138]: fxp0: rebinding lease of 192.168.1.53
Aug 31 09:28:12 farnsworth dhcpcd[14138]: fxp0: acknowledged 192.168.1.53 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 09:28:12 farnsworth dhcpcd[14138]: fxp0: checking for 192.168.1.53
Aug 31 09:28:16 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:17 farnsworth dhcpcd[14138]: fxp0: leased 192.168.1.53 for 3600000 
seconds
Aug 31 09:28:17 farnsworth dhcpcd[14138]: fxp0: carrier lost
Aug 31 09:28:19 farnsworth dhcpcd[14138]: fxp0: carrier acquired
Aug 31 09:28:19 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:19 farnsworth dhcpcd[14138]: fxp0: rebinding lease of 192.168.1.53
Aug 31 09:28:19 farnsworth dhcpcd[14138]: fxp0: acknowledged 192.168.1.53 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 09:28:19 farnsworth dhcpcd[14138]: fxp0: checking for 192.168.1.53
Aug 31 09:28:23 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:24 farnsworth dhcpcd[14138]: fxp0: leased 192.168.1.53 for 3600000 
seconds
Aug 31 09:28:25 farnsworth dhcpcd[14138]: fxp0: carrier lost
Aug 31 09:28:26 farnsworth dhcpcd[14138]: fxp0: carrier acquired
Aug 31 09:28:26 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:26 farnsworth dhcpcd[14138]: fxp0: rebinding lease of 192.168.1.53
Aug 31 09:28:26 farnsworth dhcpcd[14138]: fxp0: acknowledged 192.168.1.53 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 09:28:26 farnsworth dhcpcd[14138]: fxp0: checking for 192.168.1.53
Aug 31 09:28:30 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:32 farnsworth dhcpcd[14138]: fxp0: leased 192.168.1.53 for 3600000 
seconds
Aug 31 09:28:32 farnsworth dhcpcd[14138]: fxp0: carrier lost
Aug 31 09:28:35 farnsworth dhcpcd[14138]: fxp0: carrier acquired
Aug 31 09:28:35 farnsworth dhcpcd[14138]: fxp0: sending IPv6 Router Solicitation
Aug 31 09:28:35 farnsworth dhcpcd[14138]: fxp0: rebinding lease of 192.168.1.53
Aug 31 09:28:35 farnsworth dhcpcd[14138]: fxp0: acknowledged 192.168.1.53 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 09:28:35 farnsworth dhcpcd[14138]: fxp0: checking for 192.168.1.53
Aug 31 09:28:36 farnsworth dhcpcd[15932]: sending signal 1 to pid 14138
Aug 31 09:28:36 farnsworth dhcpcd[14138]: received SIGHUP, releasing
Aug 31 09:28:36 farnsworth dhcpcd[15932]: waiting for pid 14138 to exit
Aug 31 09:28:36 farnsworth dhcpcd[14138]: fxp0: removing interface

It will fail and retry over and over again.

Using ifconfig to see what the status of the interface is, I can see it getting 
a carrier, after some time I see it getting an IP and listing the media type as 
none. Then promptly it's disabled without an IP.

- Using dhclient instead of dhcpd doesn't show the same behavior, the interface 
stays up with an IP and I can ping DNS domains.

Since I saw the IPv6 messages in the messages from dhcpd, I decided to disable 
inet6 and stf in the kernel. Doing so gave me this output from dhcpd instead:

Aug 31 13:32:57 farnsworth dhcpcd[6828]: fxp0: carrier acquired
Aug 31 13:32:57 farnsworth dhcpcd[6828]: fxp0: rebinding lease of 192.168.1.53
Aug 31 13:32:57 farnsworth dhcpcd[6828]: fxp0: acknowledged 192.168.1.53 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 13:32:57 farnsworth dhcpcd[6828]: fxp0: checking for 192.168.1.53
Aug 31 13:33:01 farnsworth dhcpcd[6828]: fxp0: leased 192.168.1.53 for 3600000 
seconds
Aug 31 13:33:02 farnsworth dhcpcd[6828]: fxp0: carrier lost

This will loop in the same way as before. So saldy it wasn't just bogus IPv6 
leases from my router.



Before I tried repeating the issue in NetBSD, I was stuck trying to get NetBSD 
installed on my laptop. So I tried another interface so see it would work. The 
other interface is a tlp interface, reported by dmesg as:

tlp0 at cardbus1 function 0: Xircom X3201-3 Ethernet, pass 0.3
tlp0: Ethernet address 00:10:a4:f2:ae:7e
tqphy0 at tlp0 phy 0: 78Q2120 10/100 media interface, rev. 10
tqphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto

Output from dhcpd in /var/messages, running /etc/rc.d/network start and later 
stop:

Aug 31 09:34:36 farnsworth dhcpcd[13160]: version 5.6.2 starting
Aug 31 09:34:37 farnsworth dhcpcd[13160]: tlp0: waiting for carrier
Aug 31 09:34:39 farnsworth dhcpcd[13160]: tlp0: carrier acquired
Aug 31 09:34:39 farnsworth dhcpcd[13160]: tlp0: sending IPv6 Router Solicitation
Aug 31 09:34:39 farnsworth dhcpcd[13160]: tlp0: rebinding lease of 192.168.1.38
Aug 31 09:34:39 farnsworth dhcpcd[13160]: tlp0: acknowledged 192.168.1.38 from 
192.168.1.1 `ZyXEL P-320W'
Aug 31 09:34:39 farnsworth dhcpcd[13160]: tlp0: checking for 192.168.1.38
Aug 31 09:34:43 farnsworth dhcpcd[13160]: tlp0: sending IPv6 Router Solicitation
Aug 31 09:34:44 farnsworth dhcpcd[13160]: tlp0: leased 192.168.1.38 for 3600000 
seconds
Aug 31 09:34:44 farnsworth dhcpcd[13160]: forked to background, child pid 9286
Aug 31 09:34:47 farnsworth dhcpcd[9286]: tlp0: sending IPv6 Router Solicitation
Aug 31 09:34:47 farnsworth dhcpcd[9286]: tlp0: sending IPv6 Router Solicitation
Aug 31 09:34:51 farnsworth dhcpcd[9286]: tlp0: no IPv6 Routers available
Aug 31 09:35:03 farnsworth dhcpcd[14238]: sending signal 1 to pid 9286
Aug 31 09:35:03 farnsworth dhcpcd[9286]: received SIGHUP, releasing
Aug 31 09:35:03 farnsworth dhcpcd[14238]: waiting for pid 9286 to exit
Aug 31 09:35:03 farnsworth dhcpcd[9286]: tlp0: releasing lease of 192.168.1.38
Aug 31 09:35:04 farnsworth dhcpcd[9286]: tlp0: removing interface

It just works!
>How-To-Repeat:
Setup as follows:
/etc/ifconfig.fxp0:
up
media autodetect

(forcing it to another media type doesn't help)

/etc/rc.conf, add line:
ifconfig_fxp0=dhcp

Run /etc/rc.d/network start, watch it fail over and over again.

Trying to setup the network over dhcp in the installer for 6.1.4 will also 
cause the same issue. However the name servers and gateway's IPs are not listed 
by sysinst.
>Fix:
A poor work around might be to use dhclient instead of dhcpd.
Prev by Date: Re: kern/49076: USB 3.0 devices are not attached to xhci hubs
Next by Date: port-i386/49168: auich crash the system
Previous by Thread: Re: kern/49120 (RPI ld/sdmmc driver fails after a while)
Next by Thread: Re: port-i386/49167: dhcpd drop lease and connection repeatedly used with a fxp interface
Indexes:
Home | Main Index | Thread Index | Old Index