[Bug 1246236] [NEW] pxe boot from maas fails due to time out

ZhengPeng Hou zhengpeng.hou at gmail.com
Wed Oct 30 09:38:55 UTC 2013 

Public bug reported:

1 create a new vm node on a 13.10 server, attach the network to a existing openvswitch, use virtio as nic.
2 install 13.10 onto the vm
3 login to the vm via ssh, and apt-get install maas from archive. 
4 modify /etc/maas/import_pxe_files to only download pxe files for precise and saucy
5 run maas-import-pxe-files
6 create another node by using virt-manager from my laptop, and make it boot from pxe.
7 run dhcpdum on maas node, we can see dhcp works as expect, and from the console of the pxe boot node, it shows ip address has been assigned, trying to get pxelinux.0 from tftp, after couple of seconds, it fails, due to timeout.


=============================================pserv log(run pserv manually=========================================

ubuntu at maas:~$ cat /tmp/pserv.log 
2013-10-30 09:58:07+0800 [-] Log opened.
2013-10-30 09:58:07+0800 [-] twistd 13.0.0 (/usr/bin/python 2.7.5) starting up.
2013-10-30 09:58:07+0800 [-] reactor class: twisted.internet.epollreactor.EPollReactor.
2013-10-30 09:58:07+0800 [-] TFTP starting on 69
2013-10-30 09:58:07+0800 [-] Starting protocol <tftp.protocol.TFTP instance at 0x2752200>
2013-10-30 09:58:07+0800 [-] TFTP Listener started at 127.0.0.1:69
2013-10-30 09:58:07+0800 [-] TFTP starting on 69
2013-10-30 09:58:07+0800 [-] Starting protocol <tftp.protocol.TFTP instance at 0x27522d8>
2013-10-30 09:58:07+0800 [-] TFTP Listener started at 192.168.1.5:69
2013-10-30 09:58:07+0800 [-] set uid/gid 109/116
2013-10-30 09:58:45+0800 [TFTP (UDP)] Datagram received from ('192.168.1.25', 1024): <RRQDatagram(filename=pxelinux.0, mode=octet, options={'blksize': '1432', 'tsize': '0'})>
2013-10-30 09:58:45+0800 [-] RemoteOriginReadSession starting on 42340
2013-10-30 09:58:45+0800 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2752878>
2013-10-30 09:58:45+0800 [TFTP (UDP)] Datagram received from ('192.168.1.25', 1024): <RRQDatagram(filename=pxelinux.0, mode=octet, options={'blksize': '1432', 'tsize': '0'})>
2013-10-30 09:58:45+0800 [-] RemoteOriginReadSession starting on 56340
2013-10-30 09:58:45+0800 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2752f38>
2013-10-30 09:58:46+0800 [TFTP (UDP)] Datagram received from ('192.168.1.25', 1024): <RRQDatagram(filename=pxelinux.0, mode=octet, options={'blksize': '1432', 'tsize': '0'})>
2013-10-30 09:58:46+0800 [-] RemoteOriginReadSession starting on 40332
2013-10-30 09:58:46+0800 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2756320>
2013-10-30 09:58:48+0800 [TFTP (UDP)] Datagram received from ('192.168.1.25', 1024): <RRQDatagram(filename=pxelinux.0, mode=octet, options={'blksize': '1432', 'tsize': '0'})>
2013-10-30 09:58:48+0800 [-] RemoteOriginReadSession starting on 43806
2013-10-30 09:58:48+0800 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x27566c8>
2013-10-30 09:58:51+0800 [TFTP (UDP)] Datagram received from ('192.168.1.25', 1024): <RRQDatagram(filename=pxelinux.0, mode=octet, options={'blksize': '1432', 'tsize': '0'})>
2013-10-30 09:58:51+0800 [-] RemoteOriginReadSession starting on 46409
2013-10-30 09:58:51+0800 [-] Starting protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2756b00>
2013-10-30 09:58:51+0800 [-] Timed during option negotiation process
2013-10-30 09:58:51+0800 [-] (UDP Port 42340 Closed)
2013-10-30 09:58:51+0800 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2752878>
2013-10-30 09:58:51+0800 [-] Timed during option negotiation process
2013-10-30 09:58:51+0800 [-] (UDP Port 56340 Closed)
2013-10-30 09:58:51+0800 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2752f38>
2013-10-30 09:58:52+0800 [-] Timed during option negotiation process
2013-10-30 09:58:52+0800 [-] (UDP Port 40332 Closed)
2013-10-30 09:58:52+0800 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2756320>
2013-10-30 09:58:54+0800 [-] Timed during option negotiation process
2013-10-30 09:58:54+0800 [-] (UDP Port 43806 Closed)
2013-10-30 09:58:54+0800 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x27566c8>
2013-10-30 09:58:57+0800 [-] Timed during option negotiation process
2013-10-30 09:58:57+0800 [-] (UDP Port 46409 Closed)
2013-10-30 09:58:57+0800 [-] Stopping protocol <tftp.bootstrap.RemoteOriginReadSession instance at 0x2756b00>
2013-10-30 12:55:38+0800 [-] Received SIGINT, shutting down.
2013-10-30 12:55:38+0800 [-] (UDP Port 69 Closed)
2013-10-30 12:55:38+0800 [-] Stopping protocol <tftp.protocol.TFTP instance at 0x27522d8>
2013-10-30 12:55:38+0800 [-] (UDP Port 69 Closed)
2013-10-30 12:55:38+0800 [-] Stopping protocol <tftp.protocol.TFTP instance at 0x2752200>
2013-10-30 12:55:38+0800 [-] Main loop terminated.
2013-10-30 12:55:38+0800 [-] Warning: No permission to delete pid file
2013-10-30 12:55:38+0800 [-] Server Shut Down.
=======================================================End of pserv log===============================================

========================================tcpdump ===============================================================
ubuntu at maas:~$ sudo tcpdump -vvnnXS -i eth0 port 69
[sudo] password for ubuntu: 
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 65535 bytes
17:33:16.950957 IP (tos 0x0, ttl 64, id 1177, offset 0, flags [none], proto UDP (17), length 68)
    192.168.1.25.1024 > 192.168.1.5.69: [udp sum ok]  40 RRQ "pxelinux.0" octet blksize 1432 tsize 0
	0x0000:  4500 0044 0499 0000 4011 f2a1 c0a8 0119  E..D.... at .......
	0x0010:  c0a8 0105 0400 0045 0030 9796 0001 7078  .......E.0....px
	0x0020:  656c 696e 7578 2e30 006f 6374 6574 0062  elinux.0.octet.b
	0x0030:  6c6b 7369 7a65 0031 3433 3200 7473 697a  lksize.1432.tsiz
	0x0040:  6500 3000                                e.0.
17:33:17.329158 IP (tos 0x0, ttl 64, id 1435, offset 0, flags [none], proto UDP (17), length 68)
    192.168.1.25.1024 > 192.168.1.5.69: [udp sum ok]  40 RRQ "pxelinux.0" octet blksize 1432 tsize 0
	0x0000:  4500 0044 059b 0000 4011 f19f c0a8 0119  E..D.... at .......
	0x0010:  c0a8 0105 0400 0045 0030 9796 0001 7078  .......E.0....px
	0x0020:  656c 696e 7578 2e30 006f 6374 6574 0062  elinux.0.octet.b
	0x0030:  6c6b 7369 7a65 0031 3433 3200 7473 697a  lksize.1432.tsiz
	0x0040:  6500 3000                                e.0.
17:33:18.098064 IP (tos 0x0, ttl 64, id 1692, offset 0, flags [none], proto UDP (17), length 68)
    192.168.1.25.1024 > 192.168.1.5.69: [udp sum ok]  40 RRQ "pxelinux.0" octet blksize 1432 tsize 0
	0x0000:  4500 0044 069c 0000 4011 f09e c0a8 0119  E..D.... at .......
	0x0010:  c0a8 0105 0400 0045 0030 9796 0001 7078  .......E.0....px
	0x0020:  656c 696e 7578 2e30 006f 6374 6574 0062  elinux.0.octet.b
	0x0030:  6c6b 7369 7a65 0031 3433 3200 7473 697a  lksize.1432.tsiz
	0x0040:  6500 3000                                e.0.
17:33:19.635949 IP (tos 0x0, ttl 64, id 1966, offset 0, flags [none], proto UDP (17), length 68)
    192.168.1.25.1024 > 192.168.1.5.69: [udp sum ok]  40 RRQ "pxelinux.0" octet blksize 1432 tsize 0
	0x0000:  4500 0044 07ae 0000 4011 ef8c c0a8 0119  E..D.... at .......
	0x0010:  c0a8 0105 0400 0045 0030 9796 0001 7078  .......E.0....px
	0x0020:  656c 696e 7578 2e30 006f 6374 6574 0062  elinux.0.octet.b
	0x0030:  6c6b 7369 7a65 0031 3433 3200 7473 697a  lksize.1432.tsiz
	0x0040:  6500 3000                                e.0.
17:33:22.711767 IP (tos 0x0, ttl 64, id 2241, offset 0, flags [none], proto UDP (17), length 68)
    192.168.1.25.1024 > 192.168.1.5.69: [udp sum ok]  40 RRQ "pxelinux.0" octet blksize 1432 tsize 0
	0x0000:  4500 0044 08c1 0000 4011 ee79 c0a8 0119  E..D.... at ..y....
	0x0010:  c0a8 0105 0400 0045 0030 9796 0001 7078  .......E.0....px
	0x0020:  656c 696e 7578 2e30 006f 6374 6574 0062  elinux.0.octet.b
	0x0030:  6c6b 7369 7a65 0031 3433 3200 7473 697a  lksize.1432.tsiz
	0x0040:  6500 3000  
======================================================End of tcpdump===============================================

In the meanwhile, set up another vm, installed tftpd, run tftp <ip> -c
get file, the file can be downloaded correctly.  Another thing might be
helpful is /var/log/maas/maas.log is empty.

** Affects: maas (Ubuntu)
     Importance: Undecided
         Status: New

** Attachment added: "pserv.log from /var/log/maas/"
   https://bugs.launchpad.net/bugs/1246236/+attachment/3895536/+files/pserv.log

** Summary changed:

- pxe boot from maas due to time out
+ pxe boot from maas fails due to time out

-- 
You received this bug notification because you are a member of Ubuntu
Server Team, which is subscribed to maas in Ubuntu.
https://bugs.launchpad.net/bugs/1246236

Title:
  pxe boot from maas fails due to time out

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

More information about the Ubuntu-server-bugs mailing list