Crash in TFTP server booting NUC under UEFI

[Mark Shuttleworth]

And here's a different crash. In #1464894 I had two NICs of different speeds on the same cluster LAN. Removing the second non-active one (i.e. one not declared to MAAS although it is on the cluster controller) makes the PXE process work, but still shows this traceback:

2015-06-14 10:45:40+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 1947): <RRQDatagram(filename=bootx64.efi, mode=octet, options={'tsize': '0', 'blksize': '1468'})>
2015-06-14 10:45:40+0100 [-] RemoteOriginReadSession starting on 57354
2015-06-14 10:45:40+0100 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e4e51d40>
2015-06-14 10:45:40+0100 [RemoteOriginReadSession (UDP)] Unhandled Error
 Traceback (most recent call last):
   File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 73, in callWithContext
     return context.call({ILogContext: newCtx}, func, *args, **kw)
   File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
     return self.currentContext().callWithContext(ctx, func, *args, **kw)
   File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
     return func(*args,**kw)
   File "/usr/lib/python2.7/dist-packages/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
     why = selectable.doRead()
 --- <exception caught here> ---
   File "/usr/lib/python2.7/dist-packages/twisted/internet/udp.py", line 234, in doRead
     self.protocol.datagramReceived(data, addr)
   File "/usr/lib/python2.7/dist-packages/tftp/bootstrap.py", line 171, in datagramReceived
     datagram = TFTPDatagramFactory(*split_opcode(datagram))
   File "/usr/lib/python2.7/dist-packages/tftp/datagram.py", line 394, in __call__
     return datagram_class.from_wire(payload)
   File "/usr/lib/python2.7/dist-packages/tftp/datagram.py", line 323, in from_wire
     raise InvalidErrorcodeError(errorcode)
 tftp.errors.InvalidErrorcodeError: Unknown error code: 8

2015-06-14 10:45:40+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 1948): <RRQDatagram(filename=bootx64.efi, mode=octet, options={'blksize': '1468'})>
2015-06-14 10:45:40+0100 [-] RemoteOriginReadSession starting on 50579
2015-06-14 10:45:40+0100 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e4570710>
2015-06-14 10:45:40+0100 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-14 10:45:40+0100 [-] (UDP Port 50579 Closed)
2015-06-14 10:45:40+0100 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e4570710>
2015-06-14 10:45:40+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 1949): <RRQDatagram(filename=/grubx64.efi, mode=octet, options={'blksize': '512'})>
2015-06-14 10:45:40+0100 [-] RemoteOriginReadSession starting on 60534
2015-06-14 10:45:40+0100 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443c878>
2015-06-14 10:45:41+0100 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-14 10:45:41+0100 [-] (UDP Port 60534 Closed)
2015-06-14 10:45:41+0100 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443c878>
2015-06-14 10:45:41+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25300): <RRQDatagram(filename=/grub/x86_64-efi/command.lst, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:41+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25301): <RRQDatagram(filename=/grub/x86_64-efi/fs.lst, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:41+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25302): <RRQDatagram(filename=/grub/x86_64-efi/crypto.lst, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:41+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25303): <RRQDatagram(filename=/grub/x86_64-efi/terminal.lst, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:41+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25304): <RRQDatagram(filename=/grub/grub.cfg, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:41+0100 [-] RemoteOriginReadSession starting on 55024
2015-06-14 10:45:41+0100 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443e248>
2015-06-14 10:45:41+0100 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-14 10:45:41+0100 [-] (UDP Port 55024 Closed)
2015-06-14 10:45:41+0100 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443e248>
2015-06-14 10:45:41+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25305): <RRQDatagram(filename=/grub/grub.cfg-b8:ae:ed:73:f9:0a, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:41+0100 [HTTPPageGetter,client] RemoteOriginReadSession starting on 59796
2015-06-14 10:45:41+0100 [HTTPPageGetter,client] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e4e0aef0>
2015-06-14 10:45:41+0100 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-14 10:45:41+0100 [-] (UDP Port 59796 Closed)
2015-06-14 10:45:41+0100 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e4e0aef0>
2015-06-14 10:45:41+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25306): <RRQDatagram(filename=ubuntu/amd64/generic/trusty/daily/boot-kernel, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:41+0100 [-] RemoteOriginReadSession starting on 33937
2015-06-14 10:45:41+0100 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443fab8>
2015-06-14 10:45:42+0100 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-14 10:45:42+0100 [-] (UDP Port 33937 Closed)
2015-06-14 10:45:42+0100 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443fab8>
2015-06-14 10:45:42+0100 [TFTP (UDP)] Datagram received from ('192.168.9.105', 25307): <RRQDatagram(filename=ubuntu/amd64/generic/trusty/daily/boot-initrd, mode=octet, options={'blksize': '1024', 'tsize': '0'})>
2015-06-14 10:45:42+0100 [-] RemoteOriginReadSession starting on 60246
2015-06-14 10:45:42+0100 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443ca70>
2015-06-14 10:45:46+0100 [-] Timed during option negotiation process
2015-06-14 10:45:46+0100 [-] (UDP Port 57354 Closed)
2015-06-14 10:45:46+0100 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e4e51d40>
2015-06-14 10:45:50+0100 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-14 10:45:50+0100 [-] (UDP Port 60246 Closed)
2015-06-14 10:45:50+0100 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f42e443ca70>

[Raphaël Badin (rvb)]

The error code 8 comes from the "TFTP Option Extension" RFC https://tools.ietf.org/html/rfc2347. This is an error code that isn't supported by python-tx-tftp, hence the crash. This has been fixed upstream https://github.com/shylent/python-tx-tftp/pull/20 but the patch didn't make it into the packaged version of python-tx-tftp. We should get the fix included in the package but something we can do in the meantime is have monkey patch the tftp code (the patch seems trivial enough).