[Bug 1632480] Re: Latest Yakkety grub timesout when attempting to UEFI boot over IPv6

Tue Oct 11 22:49:26 UTC 2016

LaMont and I triaged the packet capture for this issue, and we believe
that the cause has to do with the IPv6 stack on the node attempting the
IPv6 UEFI boot.

After analysing the packet capture, I noticed two major issues, which
occur somewhere between grub and the UEFI BIOS code [inclusive]. The
bugs is in the the IPv6 host stack;  ICMPv6 neighbour discovery, to be
specific:

(1) Although a DHCPv6 request (and reply) is processed by the booting
machine, The IPv6 host stack never sent an IPv6 router advertisement
packet. This is a violation of the IPv6 RFCs, because in IPv6, an
address from a DHCP server does not imply an on-link prefix. In other
words, the client has configured a /128, and makes *just enough
assumptions* about being on-link to be able to talk to the server for a
little while.

(2) The booting node is not sending any IPv6 Neighbour Advertisement
packets, as can be seen by the following snippet:

    17:23:22.851379 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3:
ICMP6, neighbor solicitation, who has
2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32

Looking deeper at the packet capture, sine the IPv6 host stack on the
booting node never sends out any neighbour advertisements, the only way
the MAAS server (which in this case also happens to be the router) knows
the address is on-link is because it sends its address in a neighbour
solicitation for the router with a source link-layer address option,
which allows the MAAS server to cache the neighbour entry for just long
enough for the TFTP transfer to start (but not complete).

So the questions in my mind now is, how does grub hand off control to
the IPv6 host stack so that neighbour entries can be refreshed, neighbor
solicitations can be responded to, etc? And why isn't the node sending
out an IPv6 router advertisement when it boots, before sending a DHCPv6
request? (this seems like a UEFI firmware bug)

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to grub2 in Ubuntu.
https://bugs.launchpad.net/bugs/1632480

Title:
  Latest Yakkety grub timesout when attempting to UEFI boot over IPv6

Status in MAAS:
  New
Status in grub2 package in Ubuntu:
  New

Bug description:
  Grub timesout when downloading the initrd or the boot kernel. Packet
  capture follows:

  # Once the firmware boots IPv6, you see this:

  17:27:28.504424 IP6 :: > ff02::1:ff7d:62d: ICMP6, neighbor solicitation, who has fe80::baae:edff:fe7d:62d, length 24
  17:27:28.504427 IP6 :: > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 24
  17:27:33.392859 IP6 fe80::baae:edff:fe7d:62d.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
  17:27:33.393731 IP6 fe80::20e:c6ff:fe88:b79f.dhcpv6-server > fe80::baae:edff:fe7d:62d.dhcpv6-client: dhcp6 advertise
  17:27:37.731919 IP6 fe80::baae:edff:fe7d:62d > ff02::1:ff7d:62d: HBH ICMP6, multicast listener reportmax resp delay: 0 addr: ff02::1:ff7d:62d, length 2
  4
  17:27:37.731920 IP6 fe80::baae:edff:fe7d:62d > ff02::1:ff00:99c3: HBH ICMP6, multicast listener reportmax resp delay: 0 addr: ff02::1:ff00:99c3, length
   24
  17:27:37.731923 IP6 fe80::baae:edff:fe7d:62d.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 request
  17:27:37.732864 IP6 fe80::20e:c6ff:fe88:b79f.dhcpv6-server > fe80::baae:edff:fe7d:62d.dhcpv6-client: dhcp6 reply
  17:27:37.740288 IP6 fe80::baae:edff:fe7d:62d > ip6-allrouters: HBH ICMP6, multicast listener donemax resp delay: 0 addr: ff02::1:ff00:99c3, length 24
  17:27:38.398065 IP6 fe80::baae:edff:fe7d:62d > ff02::1:ffce:7e4c: HBH ICMP6, multicast listener reportmax resp delay: 0 addr: ff02::1:ffce:7e4c, length
   24
  17:27:38.403343 IP6 fe80::20e:c6ff:fe88:b79f > fe80::baae:edff:fe7d:62d: ICMP6, neighbor solicitation, who has fe80::baae:edff:fe7d:62d, length 32
  17:27:38.445954 IP6 fe80::baae:edff:fe7d:62d > fe80::20e:c6ff:fe88:b79f: ICMP6, neighbor advertisement, tgt is fe80::baae:edff:fe7d:62d, length 32
  17:27:38.720577 IP6 :: > ff02::1:ffce:7e4c: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:ef18:dea:b8ce:7e4c, length 24
  17:27:39.711092 IP6 2602:306:ce26:fc81:ef18:dea:b8ce:7e4c > ff02::1:ff00:1: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81::1, length 32
  17:27:39.711224 IP6 2602:306:ce26:fc81::1 > 2602:306:ce26:fc81:ef18:dea:b8ce:7e4c: ICMP6, neighbor advertisement, tgt is 2602:306:ce26:fc81::1, length 
  32
  17:27:39.711367 IP6 2602:306:ce26:fc81:ef18:dea:b8ce:7e4c.1321 > 2602:306:ce26:fc81::1.tftp:  42 RRQ "/bootx64.efi" octet tsize 0 blksize 1228 
  17:27:39.727366 IP6 2602:306:ce26:fc81::1.41956 > 2602:306:ce26:fc81:ef18:dea:b8ce:7e4c.1321: UDP, length 29
  17:27:39.727613 IP6 2602:306:ce26:fc81:ef18:dea:b8ce:7e4c.1321 > 2602:306:ce26:fc81::1.41956: UDP, length 30

  # Close to the failure, this is the packet capture:
  17:23:17.850656 IP6 2602:306:ce26:fc81::1.60878 > 2602:306:ce26:fc81:fc10:82aa:9100:99c3.25311: UDP, length 1028
  17:23:17.850854 IP6 2602:306:ce26:fc81:fc10:82aa:9100:99c3.25311 > 2602:306:ce26:fc81::1.60878: UDP, length 4
  17:23:17.851028 IP6 2602:306:ce26:fc81::1.60878 > 2602:306:ce26:fc81:fc10:82aa:9100:99c3.25311: UDP, length 1028
  17:23:17.851219 IP6 2602:306:ce26:fc81:fc10:82aa:9100:99c3.25311 > 2602:306:ce26:fc81::1.60878: UDP, length 4
  17:23:17.851400 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:18.851318 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:19.851380 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:20.853995 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:21.851380 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:22.851379 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:51.862376 IP6 2602:306:ce26:fc81:fc10:82aa:9100:99c3.25311 > 2602:306:ce26:fc81::1.60878: UDP, length 11
  17:23:51.862505 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:52.859388 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32
  17:23:53.859358 IP6 2602:306:ce26:fc81::1 > ff02::1:ff00:99c3: ICMP6, neighbor solicitation, who has 2602:306:ce26:fc81:fc10:82aa:9100:99c3, length 32

  What MAAS sees:

  2016-10-11 17:23:11 [TFTP (UDP)] Datagram received from ('2602:306:ce26:fc81:fc10:82aa:9100:99c3', 25308): <RRQDatagram(filename=b'/grub/grub.cfg-defau
  lt-amd64', mode=b'octet', options=OrderedDict([(b'blksize', b'1024'), (b'tsize', b'0')]))>
  2016-10-11 17:23:11 [ClusterClient,client] RemoteOriginReadSession starting on 37429
  2016-10-11 17:23:11 [ClusterClient,client] Starting protocol <tftp.bootstrap.RemoteOriginReadSession object at 0x7fb77b0462e8>
  2016-10-11 17:23:11 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
  2016-10-11 17:23:11 [TFTP (UDP)] Datagram received from ('2602:306:ce26:fc81:fc10:82aa:9100:99c3', 25309): <RRQDatagram(filename=b'/grub/grub.cfg-defau
  lt-amd64', mode=b'octet', options=OrderedDict([(b'blksize', b'1024'), (b'tsize', b'0')]))>
  2016-10-11 17:23:11 [-] (UDP Port 37429 Closed)
  2016-10-11 17:23:11 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession object at 0x7fb77b0462e8>
  2016-10-11 17:23:11 [ClusterClient,client] RemoteOriginReadSession starting on 42089
  2016-10-11 17:23:11 [ClusterClient,client] Starting protocol <tftp.bootstrap.RemoteOriginReadSession object at 0x7fb785d6db00>
  2016-10-11 17:23:11 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
  2016-10-11 17:23:11 [-] (UDP Port 42089 Closed)
  2016-10-11 17:23:11 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession object at 0x7fb785d6db00>
  2016-10-11 17:23:11 [TFTP (UDP)] Datagram received from ('2602:306:ce26:fc81:fc10:82aa:9100:99c3', 25310): <RRQDatagram(filename=b'ubuntu/amd64/generi$/xenial/daily/boot-kernel', mode=b'octet', options=OrderedDict([(b'blksize', b'1024'), (b'tsize', b'0')]))>
  2016-10-11 17:23:11 [-] RemoteOriginReadSession starting on 45949
  2016-10-11 17:23:11 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession object at 0x7fb779cce1d0>
  2016-10-11 17:23:14 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
  2016-10-11 17:23:14 [-] (UDP Port 45949 Closed)
  2016-10-11 17:23:14 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession object at 0x7fb779cce1d0>
  2016-10-11 17:23:14 [TFTP (UDP)] Datagram received from ('2602:306:ce26:fc81:fc10:82aa:9100:99c3', 25311): <RRQDatagram(filename=b'ubuntu/amd64/generi$/xenial/daily/boot-initrd', mode=b'octet', options=OrderedDict([(b'blksize', b'1024'), (b'tsize', b'0')]))>
  2016-10-11 17:23:14 [-] RemoteOriginReadSession starting on 60878
  2016-10-11 17:23:14 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession object at 0x7fb77b09d7f0>
  2016-10-11 17:23:23 [-] Session timed out, last wait was 1 seconds long

  What is shown in the console:

  error: timeout reading 'ubuntu/.../boot-inird' # this is provided by
  MAAS.

To manage notifications about this bug go to:
https://bugs.launchpad.net/maas/+bug/1632480/+subscriptions