trusty arm64 cloud images' dhclient does not request interface-mtu

[Ryan Finnie]

We have clouds with a custom MTU of 1400 set via DHCP, but have found that booted trusty arm64 instances are inaccessible (from e.g. ubuntu-trusty-14.04-arm64-server-20160406-uefi1.img). Despite default dhclient.conf specifying requesting interface-mtu, it is not actually being requested:

06:50:24.409363 IP (tos 0x10, ttl 128, id 0, offset 0, flags [none], proto UDP (17), length 328)
    0.0.0.0.bootpc > 255.255.255.255.bootps: [udp sum ok] BOOTP/DHCP, Request from fa:16:3e:2e:9d:4f (oui Unknown), length 300, xid 0xdc0b4b63, Flags [none] (0x0000)
          Client-Ethernet-Address fa:16:3e:2e:9d:4f (oui Unknown)
          Vendor-rfc1048 Extensions
            Magic Cookie 0x63825363
            DHCP-Message Option 53, length 1: Request
            Server-ID Option 54, length 4: 10.43.64.2
            Requested-IP Option 50, length 4: 10.43.64.8
            Parameter-Request Option 55, length 7:
              Subnet-Mask, BR, Time-Zone, Default-Gateway
              Domain-Name, Domain-Name-Server, Hostname

I was able to grab logs from a running instance (via the filesystem image; unfortunately not possible to SSH in), and saw the dhclient apparmor profile was somehow not being honored, and not loading dhclient.conf as a result:

kernel: [ 4.396573] type=1400 audit(1461300561.083:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/
sbin/dhclient" pid=406 comm="apparmor_parser"
kernel: [ 4.396589] type=1400 audit(1461300561.083:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/
usr/lib/NetworkManager/nm-dhcp-client.action" pid=406 comm="apparmor_parser"
kernel: [ 4.396597] type=1400 audit(1461300561.083:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/
usr/lib/connman/scripts/dhclient-script" pid=406 comm="apparmor_parser"
kernel: [ 4.397039] type=1400 audit(1461300561.083:5): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=406 comm="apparmor_parser"
kernel: [ 4.397051] type=1400 audit(1461300561.083:6): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=406 comm="apparmor_parser"
kernel: [ 4.397283] type=1400 audit(1461300561.083:7): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=406 comm="apparmor_parser"
kernel: [ 4.430602] Searching for RedBoot partition table in 0.flash at offset 0x107f80000
kernel: [ 4.461043] type=1400 audit(1461300561.153:8): apparmor="DENIED" operation="open" profile="/sbin/dhclient" name="/etc/ld.so.preload" pid=426 comm="dhclient" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
kernel: [ 4.501970] type=1400 audit(1461300561.193:9): apparmor="DENIED" operation="file_mmap" profile="/sbin/dhclient" name="/etc/dhcp/dhclient.conf" pid=426 comm="dhclient" requested_mask="m" denied_mask="m" fsuid=0 ouid=0
kernel: [ 4.504137] type=1400 audit(1461300561.193:10): apparmor="DENIED" operation="file_mmap" profile="/sbin/dhclient" name="/var/lib/dhcp/dhclient.eth0.leases" pid=426 comm="dhclient" requested_mask="m" denied_mask="m" fsuid=0 ouid=0
kernel: [ 44.362758] init: failsafe main process (746) killed by TERM signal
kernel: [ 44.635029] type=1400 audit(1461300601.339:11): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/sbin/dhclient" pid=924 comm="apparmor_parser"
kernel: [ 44.635046] type=1400 audit(1461300601.339:12): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=924 comm="apparmor_parser"
kernel: [ 44.635056] type=1400 audit(1461300601.339:13): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=924 comm="apparmor_parser"
kernel: [ 44.635492] type=1400 audit(1461300601.339:14): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=924 comm="apparmor_parser"
kernel: [ 44.635503] type=1400 audit(1461300601.339:15): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=924 comm="apparmor_parser"
kernel: [ 44.635735] type=1400 audit(1461300601.339:16): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=924 comm="apparmor_parser"
kernel: [ 44.641368] type=1400 audit(1461300601.339:17): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/tcpdump" pid=930 comm="apparmor_parser"

This only appears to occur on trusty arm64 images. wily and xenial arm64 work as expected, as do trusty amd64 and ppc64el.

[Dan Watkins (oddbloke)]

Hey Ryan,

We don't really have a good way of launching arm64 instances; would you be able to launch one, perform the manual intervention and then give me access so I can dig in to have a look around?

Thanks,

Dan

[Greg Mason (gmason)]

It seems that this issue is more serious than just dhclient. It appears to affect the whole system.

When adding an arm64 VM to juju 1.25.5, juju hooks will run for a while, then either stop or die. Logging into the VM, various operations seem to be hit-or-miss in terms of what will actually run. While juju install hooks are (supposedly) running, if I run top, I just get a blank screen, or top does nothing (i.e. it hangs when I try to run it).

After running /etc/init.d/apparmor teardown, the vm starts to behave a little better, but juju is still unable to complete a run of its install hooks. The expected behavior here would be for juju's hook scripts to complete or error, not keep running.

I've got a couple of these instances I can make available for debugging purposes, and can probably reproduce such an environment relatively.