NetBSD Problem Report #49167

From www@NetBSD.org  Sun Aug 31 12:01:33 2014
Return-Path: <www@NetBSD.org>
Received: from mail.netbsd.org (mail.netbsd.org [149.20.53.66])
	(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
	(Client CN "mail.netbsd.org", Issuer "Postmaster NetBSD.org" (verified OK))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 604F7B77AB
	for <gnats-bugs@gnats.NetBSD.org>; Sun, 31 Aug 2014 12:01:33 +0000 (UTC)
Message-Id: <20140831120130.E1C19B77C3@mollari.NetBSD.org>
Date: Sun, 31 Aug 2014 12:01:30 +0000 (UTC)
From: adrian.christiansen@gmail.com
Reply-To: adrian.christiansen@gmail.com
To: gnats-bugs@NetBSD.org
Subject: dhcpd drop lease and connection repeatedly used with a fxp interface
X-Send-Pr-Version: www-1.0

>Number:         49167
>Category:       kern
>Synopsis:       dhcpd drop lease and connection repeatedly used with a fxp interface
>Confidential:   no
>Severity:       serious
>Priority:       high
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Aug 31 12:05:00 +0000 2014
>Last-Modified:  Sat Sep 06 16:30: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.

>Release-Note:

>Audit-Trail:

Responsible-Changed-From-To: port-i386-maintainer->kern-bug-people
Responsible-Changed-By: martin@NetBSD.org
Responsible-Changed-When: Sun, 31 Aug 2014 14:47:47 +0000
Responsible-Changed-Why:
Sounds like a generic driver bug


From: Martin Husemann <martin@duskware.de>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: kern/49167: dhcpd drop lease and connection repeatedly used with a fxp interface
Date: Sun, 31 Aug 2014 16:47:51 +0200

 Does it work better if you disable dhcp and manually configure the
 interface IP? Especially, does fxp recognize a valid media then?

 Can you show the output of "ifconfig -m fxp0" please?

 Martin

From: Adrian Christiansen <adrian.christiansen@gmail.com>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/49167: dhcpd drop lease and connection repeatedly used with
 a fxp interface
Date: Sun, 31 Aug 2014 17:10:56 +0200

 Yes, the interface only show this behavior when I try to run dhcpd.
 Setting the IP by hand or running dhclient works just fine.

 Output from ifconfig -m fxp0:

 fxp0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> mtu 1500
     capabilities=1400<TCP4CSUM_Rx,UDP4CSUM_Rx>
     enabled=0
     address: 00:d0:59:b8:17:9a
     media: Ethernet 100baseTX
     status: active
     supported Ethernet media:
         media 10baseT
         media 10baseT mediaopt full-duplex
         media 100baseTX
         media 100baseTX mediaopt full-duplex
         media autoselect
     inet 192.168.1.53 netmask 0xffffff00 broadcast 192.168.1.255

From: Martin Husemann <martin@duskware.de>
To: gnats-bugs@NetBSD.org
Cc: adrian.christiansen@gmail.com
Subject: Re: kern/49167: dhcpd drop lease and connection repeatedly used with a fxp interface
Date: Sun, 31 Aug 2014 19:18:10 +0200

 On Sun, Aug 31, 2014 at 03:15:01PM +0000, Adrian Christiansen wrote:
 >  Yes, the interface only show this behavior when I try to run dhcpd.

 Just to make sure: you mean dhcpcd?

 Martin

From: Adrian Christiansen <adrian.christiansen@gmail.com>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/49167: dhcpd drop lease and connection repeatedly used with
 a fxp interface
Date: Sun, 31 Aug 2014 19:33:07 +0200

 Apparantly yes, I do mean dhcpcd and not dhcpd.

From: Joerg Sonnenberger <joerg@britannica.bec.de>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: port-i386/49167: dhcpd drop lease and connection repeatedly used
 with a fxp interface
Date: Sun, 31 Aug 2014 20:13:50 +0200

 On Sun, Aug 31, 2014 at 12:05:00PM +0000, adrian.christiansen@gmail.com wrote:
 > >Fix:
 > A poor work around might be to use dhclient instead of dhcpd.

 Can you try to run dhcpcd -K? That disables the use of carrier status.
 The next question would be what PHY your interface is using.

 Joerg

From: Adrian Christiansen <adrian.christiansen@gmail.com>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: port-i386/49167: dhcpd drop lease and connection repeatedly used
 with a fxp interface
Date: Sun, 31 Aug 2014 21:04:19 +0200

 2014-08-31 20:15 GMT+02:00 Joerg Sonnenberger <joerg@britannica.bec.de>:
 > The following reply was made to PR kern/49167; it has been noted by GNATS.
 >
 > From: Joerg Sonnenberger <joerg@britannica.bec.de>
 > To: gnats-bugs@NetBSD.org
 > Cc:
 > Subject: Re: port-i386/49167: dhcpd drop lease and connection repeatedly used
 >  with a fxp interface
 > Date: Sun, 31 Aug 2014 20:13:50 +0200
 >
 >  On Sun, Aug 31, 2014 at 12:05:00PM +0000, adrian.christiansen@gmail.com wrote:
 >  > >Fix:
 >  > A poor work around might be to use dhclient instead of dhcpd.
 >
 >  Can you try to run dhcpcd -K? That disables the use of carrier status.
 >  The next question would be what PHY your interface is using.
 >
 >  Joerg
 >

 That did actually work!

 I've been poking a bit more at the issue. There's something odd going on...
 At first I thought it was dhclient filling out resolv.conf that made
 dhcpcd work, it's not. It was an error on my path since I killed
 dhclient and started dhcpcd again with /etc/rc.d/network start, this
 will clear the resolv.conf and I didn't know this.

 I did however notice this:

 fxp0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> mtu 1500
     capabilities=1400<TCP4CSUM_Rx,UDP4CSUM_Rx>
     enabled=0
     address: 00:d0:59:b8:17:9a
     media: Ethernet 100baseTX
     status: active
     inet 192.168.1.53 netmask 0xffffff00 broadcast 192.168.1.255
     inet alias 192.168.1.58 netmask 0xffffff00 broadcast 192.168.1.255

 If I have an inet defined, like the one left behind from dhclient,
 dhcpcd will work every time. Even if it's something stupid like all
 the way to 11.11.11.11. However I found that dhcpcd -K would still
 work without the extra inet IP.

 Before I forget again, the phy is inphy:

 inphy0 at fxp0 phy 1: i82562ET 10/100 media interface, rev. 0
 inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto

From: Roy Marples <roy@marples.name>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/49167: dhcpd drop lease and connection repeatedly used  with a fxp interface
Date: Mon, 01 Sep 2014 10:18:36 +0100

 Hi

 dhcpcd respects the interface carrier status as reported by the kernel, 
 dhclient does not which is why it just works for you.
 -K disables this check (which Joerg suggested).

 A superfluous inet address on the interface would not affect dhcpcd 
 carrier checking.

 I would recommend running route monitor in a console and / or an 
 ifwatchd script so that you can log if the interface link is really 
 flapping or dhcpcd has a bug here. But I suspect it's either a driver or 
 connectivity issue rather than dhcpcd.

 Roy

From: Adrian Christiansen <adrian.christiansen@gmail.com>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/49167: dhcpd drop lease and connection repeatedly used with
 a fxp interface
Date: Sat, 6 Sep 2014 18:25:28 +0200

 Hi again,

 Been a busy week but I've finally got some time and calm to sit down
 with NetBSD again.

 I've followed your advice and ran two simple scripts that just wrote
 the time and interface down or up
  in a file. Just as when I was watching if with ifconfig fxp0 it's
 just going up and down when dhcpcd is running.

 But I got something interesting out of route monitor, I'll attach a
 bit of output, this is some output of dhcpcd trying to get an IP. I
 have to add that 130.244.127.161 is my ISP's DNS server 1. Which does
 not respond to ping as I found out during install.

 route monitor output:

 got message of size 88 on Sat Sep  6 18:00:23 2014
 RTM_NEWADDR: address being added to iface: len 88, metric 0, flags: <CLONING>
 sockaddrs: <NETMASK,IFP,IFA,BRD>
  255.255.255.0 fxp0:0.d0.59.b8.17.9a 192.168.1.53 192.168.1.255
 got message of size 168 on Sat Sep  6 18:00:23 2014
 RTM_ADD: Add Route: len 168, pid 0, seq 0, errno 0, flags: <UP,CLONING>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  192.168.1.0  255.255.255.0
 got message of size 152 on Sat Sep  6 18:00:23 2014
 RTM_IFINFO: iface status change: len 152, if# 1, carrier: no carrier,
 flags: <UP,BROADCAST,SIMPLEX,MULTICAST>
 got message of size 168 on Sat Sep  6 18:00:23 2014
 RTM_DELETE: Delete Route: len 168, pid 340, seq 1, errno 0, flags:
 <DONE,CLONING>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  192.168.1.0  255.255.255.0
 got message of size 192 on Sat Sep  6 18:00:23 2014
 RTM_ADD: Add Route: len 192, pid 340, seq 1, errno 0, flags: <UP,DONE>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK,IFA>
  192.168.1.0 66.78.70.30.0 255.255.255.0 192.168.1.53
 got message of size 184 on Sat Sep  6 18:00:23 2014
 RTM_ADD: Add Route: len 184, pid 340, seq 1, errno 0, flags:
 <UP,GATEWAY,DONE,STATIC>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK,IFA>
  default 192.168.1.1 0.0.0.0 192.168.1.53
 got message of size 200 on Sat Sep  6 18:00:23 2014
 RTM_ADD: Add Route: len 200, pid 0, seq 0, errno 0, flags:
 <UP,HOST,DONE,LLINFO,CLONED>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,IFP,IFA>
  192.168.1.1  fxp0:0.d0.59.b8.17.9a 192.168.1.53
 got message of size 160 on Sat Sep  6 18:00:23 2014
 RTM_DELETE: Delete Route: len 160, pid 340, seq 1, errno 0, flags:
 <GATEWAY,DONE,STATIC>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  default 192.168.1.1 default
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 168 on Sat Sep  6 18:00:25 2014
 RTM_DELETE: Delete Route: len 168, pid 340, seq 1, errno 0, flags:
 <DONE,CLONING>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  192.168.1.0  255.255.255.0
 got message of size 160 on Sat Sep  6 18:00:25 2014
 RTM_DELETE: Delete Route: len 160, pid 0, seq 0, errno 0, flags:
 <UP,HOST,DONE,LLINFO,CLONED>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY>
  192.168.1.1
 got message of size 88 on Sat Sep  6 18:00:25 2014
 RTM_DELADDR: address being removed from iface: len 88, metric 0,
 flags: <CLONING>
 sockaddrs: <NETMASK,IFP,IFA,BRD>
  255.255.255.0 fxp0:0.d0.59.b8.17.9a 192.168.1.53 192.168.1.255
 got message of size 152 on Sat Sep  6 18:00:25 2014
 RTM_IFINFO: iface status change: len 152, if# 1, carrier: active,
 flags: <UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  192.168.1.1
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  192.168.1.1
 got message of size 136 on Sat Sep  6 18:00:25 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  192.168.1.1
 got message of size 88 on Sat Sep  6 18:00:29 2014
 RTM_NEWADDR: address being added to iface: len 88, metric 0, flags: <CLONING>
 sockaddrs: <NETMASK,IFP,IFA,BRD>
  255.255.255.0 fxp0:0.d0.59.b8.17.9a 192.168.1.53 192.168.1.255
 got message of size 168 on Sat Sep  6 18:00:29 2014
 RTM_ADD: Add Route: len 168, pid 0, seq 0, errno 0, flags: <UP,CLONING>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  192.168.1.0  255.255.255.0
 got message of size 152 on Sat Sep  6 18:00:29 2014
 RTM_IFINFO: iface status change: len 152, if# 1, carrier: no carrier,
 flags: <UP,BROADCAST,SIMPLEX,MULTICAST>
 got message of size 168 on Sat Sep  6 18:00:29 2014
 RTM_DELETE: Delete Route: len 168, pid 340, seq 1, errno 0, flags:
 <DONE,CLONING>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  192.168.1.0  255.255.255.0
 got message of size 192 on Sat Sep  6 18:00:29 2014
 RTM_ADD: Add Route: len 192, pid 340, seq 1, errno 0, flags: <UP,DONE>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK,IFA>
  192.168.1.0 66.78.70.30.0 255.255.255.0 192.168.1.53
 got message of size 184 on Sat Sep  6 18:00:29 2014
 RTM_ADD: Add Route: len 184, pid 340, seq 1, errno 0, flags:
 <UP,GATEWAY,DONE,STATIC>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK,IFA>
  default 192.168.1.1 0.0.0.0 192.168.1.53
 got message of size 200 on Sat Sep  6 18:00:29 2014
 RTM_ADD: Add Route: len 200, pid 0, seq 0, errno 0, flags:
 <UP,HOST,DONE,LLINFO,CLONED>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,IFP,IFA>
  192.168.1.1  fxp0:0.d0.59.b8.17.9a 192.168.1.53
 got message of size 160 on Sat Sep  6 18:00:29 2014
 RTM_DELETE: Delete Route: len 160, pid 340, seq 1, errno 0, flags:
 <GATEWAY,DONE,STATIC>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  default 192.168.1.1 default
 got message of size 136 on Sat Sep  6 18:00:32 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 136 on Sat Sep  6 18:00:32 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 136 on Sat Sep  6 18:00:32 2014
 RTM_MISS: Lookup failed on this address: len 136, pid 0, seq 0, errno
 0, flags: <DONE>
 locks: none inits: none
 sockaddrs: <DST>
  130.244.127.161
 got message of size 168 on Sat Sep  6 18:00:32 2014
 RTM_DELETE: Delete Route: len 168, pid 340, seq 1, errno 0, flags:
 <DONE,CLONING>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY,NETMASK>
  192.168.1.0  255.255.255.0
 got message of size 160 on Sat Sep  6 18:00:32 2014
 RTM_DELETE: Delete Route: len 160, pid 0, seq 0, errno 0, flags:
 <UP,HOST,DONE,LLINFO,CLONED>
 locks: none inits: none
 sockaddrs: <DST,GATEWAY>
  192.168.1.1

 There seems to be a repeating pattern going on here.
 It seems like something is trying to verify if the link is up by
 pinging the DNS server, and fails.

 Please let me know if I can do some future testing.

 /Adrian.

 2014-09-01 11:20 GMT+02:00 Roy Marples <roy@marples.name>:
 > The following reply was made to PR kern/49167; it has been noted by GNATS.
 >
 > From: Roy Marples <roy@marples.name>
 > To: gnats-bugs@netbsd.org
 > Cc:
 > Subject: Re: kern/49167: dhcpd drop lease and connection repeatedly used  with a fxp interface
 > Date: Mon, 01 Sep 2014 10:18:36 +0100
 >
 >  Hi
 >
 >  dhcpcd respects the interface carrier status as reported by the kernel,
 >  dhclient does not which is why it just works for you.
 >  -K disables this check (which Joerg suggested).
 >
 >  A superfluous inet address on the interface would not affect dhcpcd
 >  carrier checking.
 >
 >  I would recommend running route monitor in a console and / or an
 >  ifwatchd script so that you can log if the interface link is really
 >  flapping or dhcpcd has a bug here. But I suspect it's either a driver or
 >  connectivity issue rather than dhcpcd.
 >
 >  Roy
 >

>Unformatted:

Home	PR Database Search