Date: Fri, 29 Oct 2004 11:40:41 +0200 (CEST) From: Stijn Hoop <stijn@win.tue.nl> To: FreeBSD-gnats-submit@FreeBSD.org Subject: bin/73274: dhclient DHCPDECLINE fast respawn and null pointer message Message-ID: <200410290940.i9T9efqa004674@pcwin002.win.tue.nl> Resent-Message-ID: <200410290950.i9T9oQDA026022@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
>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:
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200410290940.i9T9efqa004674>