From owner-freebsd-bugs@FreeBSD.ORG Fri Oct 29 09:50:27 2004 Return-Path: Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 053E516A4D3 for ; Fri, 29 Oct 2004 09:50:27 +0000 (GMT) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id D366F43D3F for ; Fri, 29 Oct 2004 09:50:26 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.12.11/8.12.11) with ESMTP id i9T9oQW2026025 for ; Fri, 29 Oct 2004 09:50:26 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.12.11/8.12.11/Submit) id i9T9oQDA026022; Fri, 29 Oct 2004 09:50:26 GMT (envelope-from gnats) Resent-Date: Fri, 29 Oct 2004 09:50:26 GMT Resent-Message-Id: <200410290950.i9T9oQDA026022@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-bugs@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Stijn Hoop Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id AA7C316A4CE for ; Fri, 29 Oct 2004 09:40:56 +0000 (GMT) Received: from mailhost.tue.nl (mailhost.tue.nl [131.155.2.7]) by mx1.FreeBSD.org (Postfix) with ESMTP id 0090743D4C for ; Fri, 29 Oct 2004 09:40:56 +0000 (GMT) (envelope-from stijn@pcwin002.win.tue.nl) Received: by mailhost.tue.nl (Postfix, from userid 40) id 630E814BD44; Fri, 29 Oct 2004 11:40:55 +0200 (CEST) Received: from pcwin002.win.tue.nl (pcwin002.win.tue.nl [131.155.71.72]) by mailhost.tue.nl (Postfix) with ESMTP id DCD2814BC65 for ; Fri, 29 Oct 2004 11:40:41 +0200 (CEST) Received: (from stijn@localhost) by pcwin002.win.tue.nl (8.13.1/8.13.1/Submit) id i9T9efqa004674; Fri, 29 Oct 2004 11:40:41 +0200 (CEST) (envelope-from stijn) Message-Id: <200410290940.i9T9efqa004674@pcwin002.win.tue.nl> Date: Fri, 29 Oct 2004 11:40:41 +0200 (CEST) From: Stijn Hoop To: FreeBSD-gnats-submit@FreeBSD.org X-Send-Pr-Version: 3.113 Subject: bin/73274: dhclient DHCPDECLINE fast respawn and null pointer message X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list Reply-To: Stijn Hoop List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 29 Oct 2004 09:50:27 -0000 >Number: 73274 >Category: bin >Synopsis: dhclient DHCPDECLINE fast respawn and null pointer message >Confidential: no >Severity: serious >Priority: low >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Fri Oct 29 09:50:26 GMT 2004 >Closed-Date: >Last-Modified: >Originator: Stijn Hoop >Release: FreeBSD 6.0-CURRENT i386 >Organization: >Environment: System: FreeBSD 6.0-CURRENT #30: Tue Sep 21 14:23:33 CEST 2004 stijn@pcwin002.win.tue.nl:/usr/obj/usr/src/sys/PCWIN002 i386 >Description: There seems to be a bug in dhclient(8) or dhclient-script(8), that leads to the client sending a DHCPDECLINE for a valid offer of a DHCP lease. Analogous to RedHat bug 136123, http://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=136123 it seems that dhclient-script(8) is aborting somehow, which results in the DECLINE being sent. The strange thing is that 'it sometimes works'. Here are relevant log entries (from /var/log/all.log) from the last time this has happened: Oct 28 05:04:34 pcwin002 dhclient: DHCPREQUEST on xl0 to 131.155.70.196 port 67 Oct 28 05:04:34 pcwin002 dhclient: DHCPACK from 131.155.70.196 Oct 28 05:04:34 pcwin002 dhclient: bound to 131.155.71.72 -- renewal in 19652 seconds. ... Oct 28 10:32:06 pcwin002 dhclient: DHCPREQUEST on xl0 to 131.155.70.196 port 67 Oct 28 10:32:06 pcwin002 dhclient: DHCPACK from 131.155.70.196 Oct 28 10:32:06 pcwin002 dhclient: bound to 131.155.71.72 -- renewal in 20079 seconds. ... Oct 28 16:06:45 pcwin002 dhclient: DHCPREQUEST on xl0 to 131.155.70.196 port 67 Oct 28 16:06:45 pcwin002 dhclient: DHCPACK from 131.155.70.196 Oct 28 16:06:45 pcwin002 dhclient: /usr/src/sbin/dhclient/client/../../../contrib/isc-dhcp/client/dhclient.c(2174): null pointer Oct 28 16:06:45 pcwin002 kernel: Oct 28 16:06:45 pcwin002 dhclient: /usr/src/sbin/dhclient/client/../../../contrib/isc-dhcp/client/dhclient.c(2174): null pointer Oct 28 16:06:45 pcwin002 dhclient: DHCPDECLINE on xl0 to 255.255.255.255 port 67Oct 28 16:06:45 pcwin002 dhclient: DHCPDISCOVER on xl0 to 255.255.255.255 port 67 interval 5 Oct 28 16:06:45 pcwin002 dhclient: DHCPOFFER from 131.155.70.196 Oct 28 16:06:45 pcwin002 dhclient: DHCPREQUEST on xl0 to 255.255.255.255 port 67Oct 28 16:06:45 pcwin002 dhclient: DHCPACK from 131.155.70.196 Oct 28 16:06:45 pcwin002 dhclient: /usr/src/sbin/dhclient/client/../../../contrib/isc-dhcp/client/dhclient.c(2174): null pointer [repeat ad infinitum] I see 2 problems here: - why is it that dhclient-script(8) works up until a certain point in time? - unlike in the RedHat bug report, the DHCPDECLINE messages are not rate limited; I managed to crash or at least confuse our dhcpd because this machine had been sending DECLINE's at a rate of ~120 messages a second! The null pointer message itself is harmless I think; relevant code is: %%% /* Set up the option buffer... */ memset (&client -> packet, 0, sizeof (client -> packet)); client -> packet_length = cons_options ((struct packet *)0, &client -> packet, (struct lease *)0, client, 0, (struct option_state *)0, options, &global_scope, 0, 0, 0, (struct data_string *)0, client -> config -> vendor_space_name); option_state_dereference (&options, MDL); if (client -> packet_length < BOOTP_MIN_LEN) client -> packet_length = BOOTP_MIN_LEN; option_state_dereference (&options, MDL); %%% The last line is 2174. Seems like this is a simple c&p error? Relevant configuration, can provide more on request of course: dmesg: xl0: <3Com 3c905C-TX Fast Etherlink XL> port 0xa400-0xa47f mem 0xdd800000-0xdd80007f irq 9 at device 10.0 on pci2 xl0: Ethernet address: 00:04:75:95:0a:a2 /etc/malloc.conf: [stijn@pcwin002] <~> ls -l /etc/malloc.conf lrwxr-xr-x 1 root wheel 2 9 Sep 10:25 /etc/malloc.conf -> aj /etc/rc.conf: ifconfig_xl0="DHCP" [stijn@pcwin002] <~> ls -lo /etc/resolv.conf -rw-r--r-- 1 root wheel - 68 29 Oct 08:59 /etc/resolv.conf An empty (well default, only comments) /etc/dhclient.conf No customizations to dhclient-script, and no enter or exit hooks scripts. I can try and rebuild kernel/world to a new -CURRENT but there have been no relevant dhclient commits as far as I can see. >How-To-Repeat: I wish I knew. It happened 2 or 3 times now; unfortunately I threw away my 150+ MB logfile in those cases. The symptoms were the same though (our dhcpd acting up and my /var full due to an hour worth of ~500 messages/second in my all.log). It seems that it takes some time before this happens, but I can't pinpoint the root cause. >Fix: Would be glad to have one before I crash our DHCP server again :) >Release-Note: >Audit-Trail: >Unformatted: