[pkg-dhcp-devel] Bug#675372: dhclient boothang bug

[Zebedee]

Subject: /sbin/dhclient: dhclient boothang bug
Package: isc-dhcp-client
Version: 4.1.1-P1-15+squeeze8
File: /sbin/dhclient
Severity: normal
Tags: patch

*** Please type your report below this line ***
Fixing the dhclient boot hang bug when it appeared after installing readahead-fedora.
*************************************************************************************
The dhclient program is started indirectly by ifup, called in /etc/init.d/networking
This bug delays boots while searching for internet connection on occasional random boots, and possibly is related to the operation of startpar.
It is caused by the timing of dhclient in the boot process, whether it starts in runlevel S or runlevel 2.
The networking init script that starts ifup which starts dhclient runs in runlevel S. There is a delay before dhclient starts as ifup runs many other scripts first.
The readahead-fedora package reduces this delay. A fast computer could also affect it, or possibly the installation of new software that was started during runlevel S.
If dhclient runs in S then the messages written to stderr will be displayed on the console and the boot will be delayed until it has removed itself to the background,
then runlevel 2 begins. In runlevel 2 the messages from runlevel S scripts still running are automatically placed in the background by init so no delay occurs.
Output from the console is displayed on screen during boot, providing this feature is configured.

Output from stderr can be redirected when ifup is started.
2>/dev/null to redirect stderr, or possibly >/dev/null 2>&1 to redirect stdout and stderr (stdout is not a problem here though.) 
The process should be put in the background too, appending an &. A practical test is to try variations with:
# ifdown wlan0
# ifup wlan0

So a simple solution is to change the line that calls ifup at boot, in this section of /etc/init.d/networking:

case "$1" in
start)
        process_options

        log_action_begin_msg "Configuring network interfaces"
        if ifup -a; then
            log_action_end_msg $?
        else
            log_action_end_msg $?
        fi
        ;;


to this: (careful here, "if ifup -a >/dev/null 2>&1 & ; then" failed with a syntax error.) 

case "$1" in
start)
        process_options

        log_action_begin_msg "Configuring network interfaces"
        if ifup -a >/dev/null 2>&1 &
        then
            log_action_end_msg $?
        else
            log_action_end_msg $?
        fi
        ;;
                                                                                


However, this also seems to ensure that dhclient runs later, in runlevel 2. Typically on my system the timing would vary before. Placing it in the background seems to give it a lower priority than the other processes. Writing a new initscript giving an artificial delay in runlevel S using 'sleep' proved this did work though. 

It is also possible to recompile ifup so dhclient is started with the -nw option by modifying the inet.defn file then compiling and installing the new binary.
Just rename the old /sbin/ifup to /sbin/originalifup.bak and copy the new ifup to /sbin and it works as before, using the Debian source package. 

Ifupdown: Version: 0.6.10 
Change this section in inet.defn so it includes -nw for the dhclient command as shown below:

up
    [[ifconfig %iface% hw %hwaddress%]]
    dhclient3 -pf /var/run/dhclient.%iface%.pid -lf /var/lib/dhcp3/dhclient.%iface%.leases %iface% \
        if (execable("/sbin/dhclient3"))
    dhclient -v -nw -pf /var/run/dhclient.%iface%.pid -lf /var/lib/dhcp/dhclient.%iface%.leases %iface% \
        elsif (execable("/sbin/dhclient"))
    pump -i %iface% [[-h %hostname%]] [[-l %leasehours%]] \
        elsif (execable("/sbin/pump") && mylinuxver() >= mylinux(2,1,100))
    udhcpc -n -p /var/run/udhcpc.%iface%.pid -i %iface% [[-H %hostname%]] \
           [[-c %client%]] \
        elsif (execable("/sbin/udhcpc") && mylinuxver() >= mylinux(2,2,0))
    dhcpcd [[-h %hostname%]] [[-i %vendor%]] [[-I %client%]] \
           [[-l %leasetime%]] %iface% \
        elsif (execable("/sbin/dhcpcd"))




There are various dependencies required to compile this package though. I am not aware of any advantages to doing this, except dhclient prints a few lines without delaying the boot, making it convenient for tracing the problem in syslog and bootlog.
The disadvantage is it also stops messages in the terminal which would show if a connection had been achieved when calling ifupdown manually.
As rsyslog starts near the beginning of runlevel 2, whether all the output from dhclient appears in syslog or not shows if it appears in the console and thus in the boot log. The first lines of output from dhclient:
Internet Systems Consortium DHCP Client 4.1.1-P1
Copyright 2004-2010 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/
The first large group of messages written in syslog with the same time shown are cached by the kernel and written when rsyslog starts, after this real time logging begins.
I looked at the source code for dhclient, init and ifupdown and all seemed to be operating normally, it was a matter of fine tuning the relationship between them. As ifup runs dhclient in a local environment the environment variables cannot be examined to disable writing to stderr at boot. It is possible information on whether the system is booting could be obtained from elsewhere, although I do not currently know how to do this myself.
I looked at the man page for startpar but not the source code. It is possible some option for startpar could remove this problem too.
The reason dhclient prints out info then departs later is to provide the user with feedback when it is called from the terminal. It becomes a daemon either because it has made a connection or because it times out in which case it continues trying to make a connection occasionally as a background process. When it has become a daemon it does not print messages to stderr.
It is possible to determine how to call dhclient itself manually from looking at the sequence in ifupdown, but it involves updating files and running other commands as well which are done automatically by ifupdown. The actual connection to the internet server is made by dhclient over a wired or wireless network and it runs without regard to the existence of a network connection. 
These changes may need to be adapted if the internet connection was managed by a different package to ifupdown, such as Network Manager.
The init scripts often change in new versions of Debian too. But it could still be useful to know what is causing the problem in order to find a solution. 


-- System Information:
Debian Release: 6.0.8
  APT prefers oldstable
  APT policy: (500, 'oldstable')
Architecture: i386 (i686)

Kernel: Linux 3.2.0-0.bpo.4-686-pae (SMP w/1 CPU core)
Locale: LANG=en_GB.utf8, LC_CTYPE=en_GB.utf8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages isc-dhcp-client depends on:
ii  debianutils         3.4                  Miscellaneous utilities specific t
ii  iproute             20100519-3           networking and traffic control too
ii  isc-dhcp-common     4.1.1-P1-15+squeeze8 common files used by all the isc-d
ii  libc6               2.11.3-4             Embedded GNU C Library: Shared lib

isc-dhcp-client recommends no packages.

Versions of packages isc-dhcp-client suggests:
pn  avahi-autoipd                 <none>     (no description available)
pn  resolvconf                    <none>     (no description available)

-- no debconf information
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.alioth.debian.org/pipermail/pkg-dhcp-devel/attachments/20131127/55a5b580/attachment.html>