Commissioning x86_64 node never completes, sitting at grub prompt, pserv py tbs

Looks related to the recent UEFI work, passing over to Andres.

Looks like grub is having an issue with either your network card or a miss routing of the network. Would it be possible to try and boot the machine using PXELINUX, instead of UEFI. If that works then we can confirm that it is a grubnetx64.efi issue, and can link it to that package.

[Expired for MAAS because there has been no activity for 60 days.]

The stacktrace is there because MAAS' tftp implementation doesn't know about this error (it seems it's something new). But the original problem is that the TFTP request contains an option that isn't supported by the server. We need to figure out what this option is (a full tcpdump would be helpful here).

In absence of a traffic dump, try applying e8.patch to the cluster:

    cd /usr/share/pyshared/tftp
    sudo patch -2 < .../e8.patch
    sudo restart maas-clusterd

This should give us more information about the error being sent from the remote system.

>     cd /usr/share/pyshared/tftp
>     sudo patch -2 < .../e8.patch
>     sudo restart maas-clusterd

That should read:

    cd /usr/share/pyshared/tftp
    sudo patch -p2 < .../e8.patch
    sudo restart maas-clusterd

attached log showing original error and then a boot attempt with the patch applied(starting at 2015-02-03 17:40:17).

It seems the patch worked as expected:

2015-02-03 17:40:17+0000 [TFTP (UDP)] Datagram received from ('10.61.163.200', 1161): <RRQDatagram(filename=bootx64.efi, mode=octet, options={'tsize': '0', 'blksize': '1468'})>
2015-02-03 17:40:17+0000 [TFTP (UDP)] Datagram received from ('10.61.163.200', 1161): <RRQDatagram(filename=bootx64.efi, mode=octet, options={'tsize': '0', 'blksize': '1468'})>
2015-02-03 17:40:17+0000 [-] RemoteOriginReadSession starting on 51426
2015-02-03 17:40:17+0000 [-] RemoteOriginReadSession starting on 51426
2015-02-03 17:40:17+0000 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7fc4416f45f0>
2015-02-03 17:40:17+0000 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7fc4416f45f0>
2015-02-03 17:40:17+0000 [RemoteOriginReadSession (UDP)] Got error: <tftp.datagram.ERRORDatagram object at 0x7fc4416e8a90>
2015-02-03 17:40:17+0000 [RemoteOriginReadSession (UDP)] Got error: <tftp.datagram.ERRORDatagram object at 0x7fc4416e8a90>

First attempt to transfer bootx64.efi, fails with the "Terminate transfer due to option negotiation" error (no stacktrace thanks to the patch)

2015-02-03 17:40:17+0000 [-] (UDP Port 51426 Closed)
2015-02-03 17:40:17+0000 [-] (UDP Port 51426 Closed)
2015-02-03 17:40:17+0000 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7fc4416f45f0>
2015-02-03 17:40:17+0000 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7fc4416f45f0>
2015-02-03 17:40:17+0000 [TFTP (UDP)] Datagram received from ('10.61.163.200', 1162): <RRQDatagram(filename=bootx64.efi, mode=octet, options={'blksize': '1468'})>
2015-02-03 17:40:17+0000 [TFTP (UDP)] Datagram received from ('10.61.163.200', 1162): <RRQDatagram(filename=bootx64.efi, mode=octet, options={'blksize': '1468'})>
2015-02-03 17:40:17+0000 [-] RemoteOriginReadSession starting on 34911
2015-02-03 17:40:17+0000 [-] RemoteOriginReadSession starting on 34911
2015-02-03 17:40:17+0000 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7fc4416f0440>
2015-02-03 17:40:17+0000 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7fc4416f0440>
2015-02-03 17:40:17+0000 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-02-03 17:40:17+0000 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful

Second attempt to transfer the same file (bootx64.efi); this time the transfer is successful (note how the original request didn't contain the 'tsize' this time, probably because the value was '0' the first time, and that's why the first request failed)

It's a shame we're not getting any details from the remote system as to why it doesn't like the negotiated options. Anyway, this seems to work (right?) so I'll get it landed.

Filed upstream as https://github.com/shylent/python-tx-tftp/issues/21.

(I can't set this as the bug URL for the python-tx-tftp task.)

A fix has landed upstream (https://github.com/shylent/python-tx-tftp). Can we update the Ubuntu package now?

The attachment "Add error code 8 to python-tx-tftp." seems to be a patch. If it isn't, please remove the "patch" flag from the attachment, remove the "patch" tag, and if you are a member of the ~ubuntu-reviewers, unsubscribe the team.

[This is an automated message performed by a Launchpad user owned by ~brian-murray, for any issues please contact him.]

I have the exact same issue when the controller is a VMWare ESX VM. Has this been fixed yet?

I do not understand how some files are transferred and pxeliunux file fails

2015-06-08 22:33:31-0700 [TFTP (UDP)] Datagram received from ('192.168.2.100', 1436): <RRQDatagram(filename=bootx64.efi, mode=octet, options={'blksize': '1468'})>
2015-06-08 22:33:31-0700 [-] RemoteOriginReadSession starting on 34727
2015-06-08 22:33:31-0700 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f0677601e18>
2015-06-08 22:33:32-0700 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-08 22:33:32-0700 [-] (UDP Port 34727 Closed)
2015-06-08 22:33:32-0700 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f0677601e18>
2015-06-08 22:33:33-0700 [TFTP (UDP)] Datagram received from ('192.168.2.100', 1437): <RRQDatagram(filename=/grubx64.efi, mode=octet, options={'blksize': '512'})>
2015-06-08 22:33:33-0700 [-] RemoteOriginReadSession starting on 44836
2015-06-08 22:33:33-0700 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f0676dafd40>
2015-06-08 22:33:33-0700 [RemoteOriginReadSession (UDP)] (UDP Port 44490 Closed)
2015-06-08 22:33:33-0700 [RemoteOriginReadSession (UDP)] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f06775ee908>
2015-06-08 22:33:34-0700 [RemoteOriginReadSession (UDP)] Final ACK received, transfer successful
2015-06-08 22:33:34-0700 [-] (UDP Port 44836 Closed)
2015-06-08 22:33:34-0700 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x7f0676dafd40>
2015-06-08 22:33:34-0700 [-] Unhandled Error
        Traceback (most recent call last):
          File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 392, in startReactor
            self.config, oldstdout, oldstderr, self.profiler, reactor)
          File "/usr/lib/python2.7/dist-packages/twisted/application/app.py", line 313, in runReactorWithLogging
            reactor.run()
          File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1192, in run
            self.mainLoop()
          File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 1201, in mainLoop
            self.runUntilCurrent()
        --- <exception caught here> ---
          File "/usr/lib/python2.7/dist-packages/twisted/internet/base.py", line 824, in runUntilCurrent
            call.func(*call.args, **call.kw)
          File "/usr/lib/python2.7/dist-packages/tftp/util.py", line 80, in _call_and_schedule
            self.callable(*self.callable_args, **self.callable_kwargs)
          File "/usr/lib/python2.7/dist-packages/twisted/internet/udp.py", line 254, in write
            return self.socket.send(datagram)
        exceptions.AttributeError: 'Port' object has no attribute 'socket'

Jun 8 22:34:17 maas-poc maas.lease_upload_service: [INFO] Uploading 1 DHCP leases to region controller.

Status changed to 'Confirmed' because the bug affects multiple users.

This bug was fixed in the package python-tx-tftp - 0.1~bzr38-0ubuntu4

---------------
python-tx-tftp (0.1~bzr38-0ubuntu4) wily; urgency=medium

  * debian/patches/05_lp1317705.patch: Regonise error code 8, which is
    used to terminate a transfer due to option negotiation.
    See RFC 2347, "TFTP Option Extension". (LP: #1317705)

 -- Andres Rodriguez <email address hidden> Mon, 22 Jun 2015 12:33:26 -0400

Hello Jason, or anyone else affected,

Accepted python-tx-tftp into vivid-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/python-tx-tftp/0.1~bzr38-0ubuntu4~15.04.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Hello Jason, or anyone else affected,

Accepted python-tx-tftp into trusty-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/python-tx-tftp/0.1~bzr38-0ubuntu4~14.04.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

This has been tested and verified. It works as expected. Marking it verification-done

This bug was fixed in the package python-tx-tftp - 0.1~bzr38-0ubuntu4~15.04.1

---------------
python-tx-tftp (0.1~bzr38-0ubuntu4~15.04.1) vivid-proposed; urgency=medium

  * debian/patches/05_lp1317705.patch: Regonise error code 8, which is
    used to terminate a transfer due to option negotiation.
    See RFC 2347, "TFTP Option Extension". (LP: #1317705)

 -- Andres Rodriguez <email address hidden> Mon, 22 Jun 2015 12:33:26 -0400

The verification of the Stable Release Update for python-tx-tftp has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

@brian-murray, it appears this was not released into trusty-updates as mentioned above:

root@myserver:~$ apt-cache policy python-txtftp
python-txtftp:
  Installed: 0.1~bzr38-0ubuntu4~14.04.1
  Candidate: 0.1~bzr38-0ubuntu4~14.04.1
  Version table:
 *** 0.1~bzr38-0ubuntu4~14.04.1 0
        500 http://archive.ubuntu.com/ubuntu/ trusty-proposed/main amd64 Packages
        100 /var/lib/dpkg/status
     0.1~bzr38-0ubuntu2 0
        500 http://archive.ubuntu.com/ubuntu/ trusty/main amd64 Packages

I've installed it from -proposed and confirmed that it fixes the oops on one system.

@paulgear - it wasn't released because of the other bug, LP: #1476175, which still needed verification at the time I made my comment.

This bug was fixed in the package python-tx-tftp - 0.1~bzr38-0ubuntu4~14.04.1

---------------
python-tx-tftp (0.1~bzr38-0ubuntu4~14.04.1) trusty-proposed; urgency=medium

  * debian/patches/05_lp1317705.patch: Regonise error code 8, which is
    used to terminate a transfer due to option negotiation.
    See RFC 2347, "TFTP Option Extension". (LP: #1317705)

python-tx-tftp (0.1~bzr38-0ubuntu3) utopic; urgency=medium

  * debian/patches/04-implement-rollover.patch: Resets the block number
    counter back to 0 after it reaches 2^16. (LP: #1476175)

 -- Andres Rodriguez <email address hidden> Mon, 22 Jun 2015 12:33:26 -0400