transient error results in /etc/resolv.conf not populated in iscsi root

[Scott Moser]

similar to the issue described in bug 1463461, i am now seeing transient errors resulting in /etc/resolv.conf not having any nameserver entries when it should.

The reproduce is similar
 http://bazaar.launchpad.net/~smoser/maas/maas-ephemeral-sniff/view/head:/README.txt

./get-maas-eph wily.d wily

# you probably have to fix 'ipaddr=' in ./tgt-boot-test
# or set HOST_IP= to some ip address valid for your host.

./tgt-boot-test wily.d/root-image wily.d/hwe-w/boot-kernel wily.d/hwe-w/boot-initrd

login with 'ubuntu:passw0rd'
and cat /etc/resolv.conf.
you should have something there.

Related bugs:
 * bug 1463461: resolvconf not updated by /lib/systemd/system/ifup@.service.d/open-iscsi.conf
 * bug 1432829: resolv.conf not updated correctly for interfaces configured in initramfs

ProblemType: Bug
DistroRelease: Ubuntu 15.10
Package: open-iscsi 2.0.873-3ubuntu12
ProcVersionSignature: User Name 4.2.0-10.12-generic 4.2.0
Uname: Linux 4.2.0-10-generic x86_64
ApportVersion: 2.18.1-0ubuntu1
Architecture: amd64
Date: Tue Sep 29 19:56:40 2015
ProcEnviron:
 TERM=linux
 PATH=(custom, no user)
 XDG_RUNTIME_DIR=<set>
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: open-iscsi
UpgradeStatus: No upgrade log present (probably fresh install)

[Martin Pitt (pitti)]

Theory (needs to be checked): open-iscsi's initramfs-tools integration makes ifupdown think that it already up'ed that interface. So there's actually nothing in the boot sequence which would call resolvconf -a for this interface; I guess open-iscsi's init jobs need to do that then?

[Scott Moser (smoser)]

I've modified the image a bit, to add 'set -x' to /sbin/resolvconf, and to also echo '::: "$0" "$@"' in /sbin/resolvconf before the -x . so you can easily find those by looking for '::: /sbin/resolvconf'

I've caught in pass and fail and attach journalctl output here.
Also showing output of some things inside just for reference. The only differnce between pass and fail in the following output is presence of 'nameserver 10.0.2.3' The fail case is shown, pass would have that line after DO NOT EDIT.

$ cat /etc/resolv.conf
# Dynamic resolv.conf(5) file for glibc resolver(3) generated by resolvconf(8)
# DO NOT EDIT THIS FILE BY HAND -- YOUR CHANGES WILL BE OVERWRITTEN

$ ls -l /etc/resolv.conf
lrwxrwxrwx 1 root root 29 Oct 3 21:37 /etc/resolv.conf -> ../run/resolvconf/resolv.conf

$ cat /run/network/ifstate
eth0=eth0
lo=lo

$ cat /run/net-eth0.conf
DEVICE='eth0'
PROTO='dhcp'
IPV4ADDR='10.0.2.15'
IPV4BROADCAST='10.0.2.255'
IPV4NETMASK='255.255.255.0'
IPV4GATEWAY='10.0.2.2'
IPV4DNS0='10.0.2.3'
IPV4DNS1='0.0.0.0'
HOSTNAME=''
DNSDOMAIN=''
NISDOMAIN=''
ROOTSERVER='10.0.2.2'
ROOTPATH=''
filename=''
UPTIME='16'
DHCPLEASETIME='86400'
DOMAINSEARCH=''

[Scott Moser (smoser)]

ok. a bit more debug, i think i have the problem understood now.
The last set of changes to open-iscsi added moved the invocation of /lib/open-iscsi/net-interface-handler to udev rules in /lib/open-iscsi/net-interface-handler .

I caught the output of /lib/open-iscsi/net-interface-handler via modification of the program, redirecting its output to /run/net-interface-handler.log and see this log (http://paste.ubuntu.com/12689756/) with a snippet.

I believe the problem is that the udev rule is running before the resolvconf service has run.

| :: start /lib/open-iscsi/net-interface-handler start
| <snip>
| ::: /sbin/resolvconf -a eth0.iscsi-network
| + PATH=/sbin:/bin
| + MYNAME=resolvconf
| + RUN_DIR=/run/resolvconf
| + ENABLE_UPDATES_FLAGFILE=/run/resolvconf/enable-updates
| + POSTPONED_UPDATE_FLAGFILE=/run/resolvconf/postponed-update
| + CMD=-a
| + IFACE=eth0.iscsi-network
| + [ ! eth0.iscsi-network ]
| + [ -d /run/resolvconf/interface ]
| + report_err /run/resolvconf/interface either does not exist or is not a directo
| ry
| + echo resolvconf: Error: /run/resolvconf/interface either does not exist or is
| not a directory
| resolvconf: Error: /run/resolvconf/interface either does not exist or is not a directory
| + exit 1
| + set +x
| :: end /lib/open-iscsi/net-interface-handler start
| <snip>

[Scott Moser (smoser)]

for easy reference, the changes to run as udev rule are :
 http://bazaar.launchpad.net/~ubuntu-branches/ubuntu/wily/open-iscsi/wily/revision/51
in upstart init resolvconf started on the blocking 'mounted MOUNTPOINT=/run'.

[Martin Pitt (pitti)]

Thanks Scott! This indeed is the culprit, setting to triaged.

[Martin Pitt (pitti)]

Took a bit to get the reproducer running (no pointer to xkvm), but I can reproduce this now. This can be triggered much more reliably by adding "ExecStartPre=/bin/sleep 5" to /lib/systemd/system/resolvconf.service .

I tested/uploaded a fix.

[Launchpad Janitor (janitor)]

This bug was fixed in the package open-iscsi - 2.0.873-3ubuntu13

---------------
open-iscsi (2.0.873-3ubuntu13) wily; urgency=medium

  * debian/net-interface-handler: Create the resolvconf dir, to avoid failure
    when resolvconf did not start yet; the udev rules run in parallel with
    it. (LP: #1501033)

 -- Martin Pitt <email address hidden> Tue, 06 Oct 2015 07:05:48 +0200