dhclient-script attempts to write /etc/resolv.conf before it is writable

[Scott Moser]

dhclient-script has a function in it 'wait_for_rw'. that basically tries to wait and sleep until /etc is writeable.
The check of 'is writeable' is:
   [ -w /etc ]

For some period during early boot, that check is returning true, while subsequent actual write to /etc/resolv.conf is failing.

I suspect what is happening is that '[ -w /etc ]' begins returning true as soon as 'mount -o remount,rw' issues the kernel call to remount read-write, but there is a period of time after that when the kernel is still refusing writes.

I've seen this, and put some debug code into /sbin/dhclient-script, and sent /etc/init/network-* output to the console to see what was going on.

I'm seeing this when booting the oneiric beta-2 cloud-image (20110921.1) under kvm with an attached virtual cdrom (with ovf data on it).

I'll attach the whole console.log, but here is the interesting part:
08 can't create /var/lib/dhcp3/dhclient.eth0.leases: No such file or directory
09 Listening on LPF/eth0/52:54:00:12:34:56
10 Sending on LPF/eth0/52:54:00:12:34:56
11 Sending on Socket/fallback
12 DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
13 DHCPOFFER of 10.0.2.15 from 10.0.2.2
14 DHCPREQUEST of 10.0.2.15 on eth0 to 255.255.255.255 port 67
15 DHCPACK of 10.0.2.15 from 10.0.2.2
16 ls: cannot access /etc/resolv.conf: No such file or directory
17 w=true W=false
18 ls: cannot access /etc/resolv.conf: No such file or directory
19 w=true W=false
20 ls: cannot access /etc/resolv.conf: No such file or directory
21 w=true W=true
22 -rw-r--r-- 1 root root 0 Sep 23 01:46 /etc/resolv.conf
23 can't create /var/lib/dhcp3/dhclient.eth0.leases: No such file or directory
24 bound to 10.0.2.15 -- renewal in 39483 seconds.
25 The disk drive for / is not ready yet or not present.
26 Continue to wait, or Press S to skip mounting or M for manual recovery
27 The disk drive for /tmp is not ready yet or not present.
28 Continue to wait, or Press S to skip mounting or M for manual recovery
29 cloud-init start-local running: Fri, 23 Sep 2011 01:46:13 +0000. up 6.83 seconds

Lines 16 to 22 are output of my modified dhclient-script, from the following loop.
| while :; do
| w=false; W=false
| [ -w /etc ] && w=true
| { : >> /etc/resolv.conf ; } 2>/dev/null &&
| W=true
| echo "w=$w W=$W"
| ls -l /etc/resolv.conf
| $w && $W && break
| sleep .1
| done

So, the '[ -w /etc ]' check was returning true, while the attempt to write to /etc/resolv.conf was returning false. Its not as if this happened once, and / became rw in between. It was happened 3 times.
That demonstrates that the original /sbin/dhclient-script's check is failing, and its exiting the 'wait_for_rw' too early.

The "is not ready yet" messages on lines 25 to 28 i believe are simply a result of the disk being slow, and the kernel taking a while to mount rw.
On line 29, cloud-init 'start-local' comes up, which is an upstart job with 'start on mounted MOUNTPOINT=/'.

So, a solution for this, which actually better answers the question of "is /etc/resolv.conf writable?" is the following:

--- dhclient-script.dist 2011-09-22 22:16:52.188538963 -0400
+++ dhclient-script 2011-09-22 22:18:07.158908650 -0400
@@ -29,7 +29,7 @@ wait_for_rw() {

     # Wait for /etc/resolv.conf to become writable
     if [ "$rootmode" = "rw" ]; then
- while [ ! -w /etc ]; do
+ while ! { : >> /etc/resolv.conf; } 2>/dev/null; do
             sleep 0.1
         done
     fi

Further changes to dhclient-script are necessary since it actually tries to write to a temp file in /etc/resolv.conf.dhclient-new. That should probably be to /run or another expected tmpfs as /etc/ might not be writable at all, and /etc/resolv.conf a link to a writeable location outside of /etc.

ProblemType: Bug
DistroRelease: Ubuntu 11.10
Package: isc-dhcp-client 4.1.1-P1-17ubuntu9 [modified: sbin/dhclient-script]
ProcVersionSignature: Ubuntu 3.0.0-11.18-virtual 3.0.4
Uname: Linux 3.0.0-11-virtual x86_64
ApportVersion: 1.23-0ubuntu1
Architecture: amd64
Date: Fri Sep 23 01:49:58 2011
DhclientLeases:

ProcEnviron:
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: isc-dhcp
UpgradeStatus: No upgrade log present (probably fresh install)

[Scott Moser (smoser)]

I'm just attaching 'setup.tar.gz' mostly for my own personal future reference.
This documents how you can recreate this issue easily.

[Launchpad Janitor (janitor)]

This bug was fixed in the package isc-dhcp - 4.1.1-P1-17ubuntu10

---------------
isc-dhcp (4.1.1-P1-17ubuntu10) oneiric; urgency=low

  * make sure writing of /etc/resolv.conf actually waits until the file is
    writable (LP: #856984)
 -- Scott Moser <email address hidden> Fri, 23 Sep 2011 11:26:29 -0400

[Scott Moser (smoser)]

I opened bug 857524 to address further changes to dhclient-script.