From owner-freebsd-rc@FreeBSD.ORG Wed Feb 22 22:28:57 2012 Return-Path: Delivered-To: freebsd-rc@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 4E4301065678 for ; Wed, 22 Feb 2012 22:28:57 +0000 (UTC) (envelope-from freebsd@damnhippie.dyndns.org) Received: from qmta02.emeryville.ca.mail.comcast.net (qmta02.emeryville.ca.mail.comcast.net [76.96.30.24]) by mx1.freebsd.org (Postfix) with ESMTP id 323EE8FC08 for ; Wed, 22 Feb 2012 22:28:56 +0000 (UTC) Received: from omta21.emeryville.ca.mail.comcast.net ([76.96.30.88]) by qmta02.emeryville.ca.mail.comcast.net with comcast id d9wW1i0041u4NiLA2AUwGQ; Wed, 22 Feb 2012 22:28:56 +0000 Received: from damnhippie.dyndns.org ([24.8.232.202]) by omta21.emeryville.ca.mail.comcast.net with comcast id dAUv1i00T4NgCEG8hAUvYR; Wed, 22 Feb 2012 22:28:56 +0000 Received: from [172.22.42.240] (revolution.hippie.lan [172.22.42.240]) by damnhippie.dyndns.org (8.14.3/8.14.3) with ESMTP id q1MMSs53005227; Wed, 22 Feb 2012 15:28:54 -0700 (MST) (envelope-from freebsd@damnhippie.dyndns.org) From: Ian Lepore To: Warren Block In-Reply-To: References: <1329938748.21804.8.camel@revolution.hippie.lan> Content-Type: text/plain; charset="us-ascii" Date: Wed, 22 Feb 2012 15:28:53 -0700 Message-ID: <1329949733.1063.6.camel@revolution.hippie.lan> Mime-Version: 1.0 X-Mailer: Evolution 2.32.1 FreeBSD GNOME Team Port Content-Transfer-Encoding: 7bit Cc: freebsd-rc@freebsd.org Subject: Re: dhclient SYNCDHCP messiness X-BeenThere: freebsd-rc@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: "Discussion related to /etc/rc.d design and implementation." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 22 Feb 2012 22:28:57 -0000 On Wed, 2012-02-22 at 14:08 -0700, Warren Block wrote: > On Wed, 22 Feb 2012, Ian Lepore wrote: > > > On Wed, 2012-02-22 at 11:40 -0700, Warren Block wrote: > >> In /etc/rc.conf: > >> > >> ifconfig_em0="SYNCDHCP" > >> > >> dhclient runs on startup, then later tries to run again: > >> > >> Starting dhclient. > >> em0: no link ... > >> . > >> . > >> got link > >> (...) > >> Starting Network: lo0 em0. > >> (...) > >> Starting devd. > >> Starting ums0 moused > >> . > >> dhclient already running? (pid=344). > >> Creating and/or trimming log files > >> > >> So is this from /etc/network.subr starting dhclient because the > >> interface is set to DHCP, then /etc/rc.d/dhclient running directly > >> later? > >> > >> This is with > >> > >> FreeBSD lightning 8.3-PRERELEASE FreeBSD 8.3-PRERELEASE #0: Tue Feb 21 22:25:30 MST 2012 > >> root@lightning:/usr/obj/usr/src/sys/LIGHTNING i386 > > > > From the sequence of things there it looks like the second invocation > > may be from a devd rule, but I thought all the standard rules used > > "dhclient quietstart" and that one of the effects of that was to supress > > the "already running" warning. > > The devd rule triggers on a link up event. This is an em(4) card that > does not do the multiple up/down events on start like an re(4) card. > But easy to test. ...And interestingly enough, commenting out lines > 51-56 of devd.conf stops the double call: > > DHCPREQUEST on em0 to 255.255.255.255 port 67 > DHCPACK from 10.0.0.1 > bound to 10.0.0.8 -- renewal in 300 seconds. > Starting Network: lo0 em0. > lo0: flags=8049 metric 0 mtu 16384 > options=3 > inet 127.0.0.1 netmask 0xff000000 > em0: flags=8843 metric 0 mtu 9216 > options=9b > ether 00:02:b3:a9:93:d7 > inet 10.0.0.8 netmask 0xffffff00 broadcast 10.0.0.255 > media: Ethernet autoselect (1000baseT ) > status: active > Starting devd. > Starting ums0 moused > . > Creating and/or trimming log files > > For completeness, there's an unconnected re(4) card built into the > motherboard that shows "re0: link state changed to DOWN" immediately > after the "Starting devd." message. > > AFAIK, it should happen like this: > > ifconfig em0 > em0 changes to up > dhclient em0 (sync) > wait until em0 gets a DHCP lease or fails > devd (em0 is already up, devd should do nothing) > > So I guess the question is: why is devd seeing a link up event there? > > > I updated a couple systems to 8.3-{PRERELEASE,BETA1} over the past few > > days and I haven't seen such a glitch. I don't think it should make a > > difference, but I use synchronous_dhclient=YES and ifconfig_foo=DHCP > > That's a good point: testing... nope, it does the same thing as > "SYNCDHCP". > > First, let me correct myself: I *am* seeing exactly this glitch, I just hadn't noticed it until a few minutes ago when I rebooted and looked much more closely. Devd sees the link-up event because it sees all the events that happened before it started (for some definition of "all"; there's probably some reasonable list-length or buffer size limit somewhere). I rebooted to test my vague memory on this... boot into single-user mode and manually run /sbin/devd -D and you'll see it processing the buffered events before daemonizing. For some reason I had to mount / writeable before running devd in single-user or it failed. I now suspect (but haven't tested to confirm) that this message may be a side effect of r226345 which replaced some one-off pidfile logic in rc.d/dhclient with use of the standard rc_pid scheme, which is what is doing the whining. I think the old one-off code to deal with the pidfile avoided whining in the 'quietstart' case. -- Ian