Skip to content

DHCP never gets a response #72

Closed
Closed
DHCP never gets a response#72
@sgrove

Description

@sgrove
sgrove
opened on Aug 13, 2016

Trying on two different systems using a modified tcpip package with some extra logging, I can't get my solo5 virtio unikernel to ever pickup an IP address via DHCP.

If I hardcode the IP setup the unikernel gets a bit further, but hits another (unrelated) problem later on. I suspect that if it didn't however, that anything relying on the network still wouldn't work.

I compiled the unikernel in a docker container:
mirage configure -t virtio --dhcp=true --show_errors=true --report_errors=true --net=direct --network=tap0 && make clean && make

I've also attached a tar of the disk image that's a result of running bin/unikernel-mkimage.sh tmp/disk.raw mir-riseos.virtio

mir-riseos-11.tar.gz

First, on GCE:

$ gcloud compute instances get-serial-port-output --zone us-west1-a mir-riseos-10
SeaBIOS (version 1.8.2-20160510_123855-google)
Total RAM Size = 0x0000000026600000 = 614 MiB
CPU Mhz=2201
CPUs found: 1     Max CPUs supported: 1
found virtio-scsi at 0:3
virtio-scsi vendor='Google' product='PersistentDisk' rev='1' type=0 removable=0
virtio-scsi blksize=512 sectors=2097152 = 1024 MiB
drive 0x000f5500: PCHS=0/0/0 translation=lba LCHS=1024/32/63 s=2097152
Booting from Hard Disk 0...

SYSLINUX 6.03 2014-10-06 Copyright (C) 1994-2014 H. Peter Anvin et al
Loading unikernel.bin... ok
            |      ___|
  __|  _ \  |  _ \ __ \
\__ \ (   | | (   |  ) |
____/\___/ _|\___/____/
multiboot: Using memory: 0x100000 - 0x265fd000
Initializing the KVM Paravirtualized clock.
virtio_config: device_id=8, interrupt_line=b
Found unknown virtio device!
virtio_config: device_id=1, interrupt_line=b
Found virtio network device with MAC: 42 01 0a 8a 00 02 
Solo5: new bindings
STUB: getenv() called
Netif: plugging into tap0 with mac 42:01:0a:8a:00:02
Netif: connect tap0
2016-08-13 23:13.50: INF [ethif] Connected Ethernet interface 42:01:0a:8a:00:02
2016-08-13 23:13.50: INF [arpv4] Connected arpv4 device on 42:01:0a:8a:00:02
2016-08-13 23:13.50: INF [udp] UDP interface connected on 0.0.0.0
STUB: open() called
STUB: getpid() called
STUB: getppid() called
2016-08-13 23:13.50: INF [tcpip-stack-direct] Manager: connect
2016-08-13 23:13.50: INF [tcpip-stack-direct] Manager: configuring
2016-08-13 23:13.50: INF [tcpip-stack-direct] (using a modified NOISY tcpip stack)
2016-08-13 23:13.50: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:13.50: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:13.50: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:13.50: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:14.01: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:14.01: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:14.01: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:14.01: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:14.11: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:14.11: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:14.11: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:14.11: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:14.21: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:14.21: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:14.21: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:14.21: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:14.31: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:14.31: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:14.31: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:14.31: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:14.42: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:14.42: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:14.42: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:14.42: INF [udp] Writing UDP Packet: -> 67

Then on my OSX machine (where I have a bit more control), I see a bit more activity. First I convert the raw disk image to a VDI for VirtualBox, and then boot it up (with all the virtio settings I could figure out). Here's the serial output:


SYSLINUX 6.03  Copyright (C) 1994-2014 H. Peter Anvin et al
Loading unikernel.bin... ok
            |      ___|
  __|  _ \  |  _ \ __ \
\__ \ (   | | (   |  ) |
____/\___/ _|\___/____/
multiboot: Using memory: 0x100000 - 0x3ff0000
Initializing the KVM Paravirtualized clock.
virtio_config: device_id=1, interrupt_line=a
Found virtio network device with MAC: 08 00 27 11 0f a9 
Solo5: new bindings
STUB: getenv() called
Netif: plugging into tap0 with mac 08:00:27:11:0f:a9
Netif: connect tap0
2016-08-13 23:21.53: INF [ethif] Connected Ethernet interface 08:00:27:11:0f:a9
2016-08-13 23:21.54: INF [arpv4] Connected arpv4 device on 08:00:27:11:0f:a9
2016-08-13 23:21.54: INF [udp] UDP interface connected on 0.0.0.0
STUB: open() called
STUB: getpid() called
STUB: getppid() called
2016-08-13 23:21.54: INF [tcpip-stack-direct] Manager: connect
2016-08-13 23:21.54: INF [tcpip-stack-direct] Manager: configuring
2016-08-13 23:21.54: INF [tcpip-stack-direct] (using a modified NOISY tcpip stack)
2016-08-13 23:21.54: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:21.54: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:21.54: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:21.54: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:22.04: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:22.05: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:22.05: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:22.05: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:22.10: INF [ipv4] IP packet received:  (10.0.1.6 -> 255.255.255.255: proto 17, ttl 64)

2016-08-13 23:22.10: INF [udp] UDP packet received:  (17500 -> 17500)

2016-08-13 23:22.10: INF [ipv4] IP packet received:  (10.0.1.6 -> 10.0.1.255: proto 17, ttl 64)

2016-08-13 23:22.10: INF [udp] UDP packet received:  (17500 -> 17500)

2016-08-13 23:22.15: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:22.15: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:22.15: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:22.15: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:22.16: INF [ipv4] IP packet received:  (10.0.1.6 -> 10.0.1.255: proto 17, ttl 64)

2016-08-13 23:22.16: INF [udp] UDP packet received:  (57621 -> 57621)

2016-08-13 23:22.26: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:22.26: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:22.26: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:22.26: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:22.31: INF [ipv4] IP packet received:  (10.0.1.6 -> 239.255.255.250: proto 17, ttl 1)

2016-08-13 23:22.31: INF [udp] UDP packet received:  (57849 -> 1900)

2016-08-13 23:22.31: INF [ipv4] IP packet received:  (10.0.1.6 -> 239.255.255.250: proto 17, ttl 1)

2016-08-13 23:22.31: INF [udp] UDP packet received:  (57203 -> 1900)

2016-08-13 23:22.32: INF [ipv4] IP packet received:  (10.0.1.6 -> 239.255.255.250: proto 17, ttl 1)

2016-08-13 23:22.32: INF [udp] UDP packet received:  (57849 -> 1900)

2016-08-13 23:22.33: INF [ipv4] IP packet received:  (10.0.1.6 -> 239.255.255.250: proto 17, ttl 1)

2016-08-13 23:22.33: INF [udp] UDP packet received:  (57849 -> 1900)

2016-08-13 23:22.34: INF [ipv4] IP packet received:  (10.0.1.6 -> 239.255.255.250: proto 17, ttl 1)

2016-08-13 23:22.34: INF [udp] UDP packet received:  (57849 -> 1900)

2016-08-13 23:22.36: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:22.36: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:22.36: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:22.36: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:22.40: INF [ipv4] IP packet received:  (10.0.1.6 -> 255.255.255.255: proto 17, ttl 64)

2016-08-13 23:22.40: INF [udp] UDP packet received:  (17500 -> 17500)

2016-08-13 23:22.40: INF [ipv4] IP packet received:  (10.0.1.6 -> 10.0.1.255: proto 17, ttl 64)

2016-08-13 23:22.40: INF [udp] UDP packet received:  (17500 -> 17500)

2016-08-13 23:22.46: INF [ipv4] IP packet received:  (10.0.1.6 -> 10.0.1.255: proto 17, ttl 64)

2016-08-13 23:22.46: INF [udp] UDP packet received:  (57621 -> 57621)

2016-08-13 23:22.47: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:22.47: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:22.47: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:22.47: INF [udp] Writing UDP Packet: -> 67 

2016-08-13 23:22.50: INF [ipv4] IP packet received:  (10.0.1.6 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:22.50: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:22.50: INF [ipv4] IP packet received:  (10.0.1.2 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:22.50: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:22.50: INF [ipv4] IP packet received:  (10.0.1.1 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:22.50: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:22.57: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:22.57: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:22.57: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:22.57: INF [udp] Writing UDP Packet: -> 67

(here's the ifconfig output in case it's useful for the above)

$ ifconfig
lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> mtu 16384
    options=3<RXCSUM,TXCSUM>
    inet6 ::1 prefixlen 128
    inet 127.0.0.1 netmask 0xff000000
    inet6 fe80::1%lo0 prefixlen 64 scopeid 0x1
    nd6 options=1<PERFORMNUD>
gif0: flags=8010<POINTOPOINT,MULTICAST> mtu 1280
stf0: flags=0<> mtu 1280
en0: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 1500
    ether ac:bc:32:9f:40:5d
    inet 10.0.1.6 netmask 0xffffff00 broadcast 10.0.1.255
    media: autoselect
    status: active
en1: flags=963<UP,BROADCAST,SMART,RUNNING,PROMISC,SIMPLEX> mtu 1500
    options=60<TSO4,TSO6>
    ether 6a:00:01:0d:ce:a0
    media: autoselect <full-duplex>
    status: inactive
en2: flags=963<UP,BROADCAST,SMART,RUNNING,PROMISC,SIMPLEX> mtu 1500
    options=60<TSO4,TSO6>
    ether 6a:00:01:0d:ce:a1
    media: autoselect <full-duplex>
    status: inactive
p2p0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> mtu 2304
    ether 0e:bc:32:9f:40:5d
    media: autoselect
    status: inactive
awdl0: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> mtu 1484
    ether 5e:a6:38:23:07:69
    inet6 fe80::5ca6:38ff:fe23:769%awdl0 prefixlen 64 scopeid 0x8
    nd6 options=1<PERFORMNUD>
    media: autoselect
    status: active
bridge0: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 1500
    options=63<RXCSUM,TXCSUM,TSO4,TSO6>
    ether ae:bc:32:f9:59:00
    Configuration:
        id 0:0:0:0:0:0 priority 0 hellotime 0 fwddelay 0
        maxage 0 holdcnt 0 proto stp maxaddr 100 timeout 1200
        root id 0:0:0:0:0:0 priority 0 ifcost 0 port 0
        ipfilter disabled flags 0x2
    member: en1 flags=3<LEARNING,DISCOVER>
            ifmaxaddr 0 port 5 priority 0 path cost 0
    member: en2 flags=3<LEARNING,DISCOVER>
            ifmaxaddr 0 port 6 priority 0 path cost 0
    nd6 options=1<PERFORMNUD>
    media: <unknown type>
    status: inactive
vboxnet0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> mtu 1500
    ether 0a:00:27:00:00:00
    inet 192.168.56.1 netmask 0xffffff00 broadcast 192.168.56.255

Finally, trying the raw disk image with just qemu on OSX, I get:

$ sudo qemu-system-x86_64 -s -nographic -cpu Westmere -name mirage -m 1024 -net nic,model=virtio -net tap,script=./tap-up.sh,downscript=./tap-down.sh -drive file=disk.raw,format=raw,if=virtio

---
warning: TCG doesn't support requested feature: CPUID.01H:EDX.vme [bit 1]

SYSLINUX 6.03  Copyright (C) 1994-2014 H. Peter Anvin et al
Loading unikernel.bin... ok
            |      ___|
  __|  _ \  |  _ \ __ \
\__ \ (   | | (   |  ) |
____/\___/ _|\___/____/
multiboot: Using memory: 0x100000 - 0x3ffde000
TSC frequency estimate is 2794422240 Hz
virtio_config: device_id=1, interrupt_line=b
Found virtio network device with MAC: 52 54 00 12 34 56
virtio_config: device_id=2, interrupt_line=b
host features: 71000ed4: 2 4 6 7 9 10 11 24 28 29 30
Found virtio block device with capacity: 2097152 * 512 = 1073741824
queue size is 128
Solo5: new bindings
STUB: getenv() called
Netif: plugging into tap0 with mac 52:54:00:12:34:56
Netif: connect tap0
2016-08-13 23:25.38: INF [ethif] Connected Ethernet interface 52:54:00:12:34:56
2016-08-13 23:25.38: INF [arpv4] Connected arpv4 device on 52:54:00:12:34:56
2016-08-13 23:25.38: INF [udp] UDP interface connected on 0.0.0.0
STUB: open() called
STUB: getpid() called
STUB: getppid() called
2016-08-13 23:25.38: INF [tcpip-stack-direct] Manager: connect
2016-08-13 23:25.38: INF [tcpip-stack-direct] Manager: configuring
2016-08-13 23:25.38: INF [tcpip-stack-direct] (using a modified NOISY tcpip stack)
2016-08-13 23:25.38: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:25.38: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:25.38: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:25.38: INF [udp] Writing UDP Packet: -> 67

2016-08-13 23:25.38: INF [ipv4] IP packet received:  (0.0.0.0 -> 255.255.255.255: proto 17, ttl 255)

2016-08-13 23:25.38: INF [udp] UDP packet received:  (68 -> 67)

2016-08-13 23:25.41: INF [ipv4] IP packet received:  (0.0.0.0 -> 255.255.255.255: proto 17, ttl 255)

2016-08-13 23:25.41: INF [udp] UDP packet received:  (68 -> 67)

2016-08-13 23:25.45: INF [ipv4] IP packet received:  (0.0.0.0 -> 255.255.255.255: proto 17, ttl 255)

2016-08-13 23:25.45: INF [udp] UDP packet received:  (68 -> 67)

2016-08-13 23:25.48: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:25.48: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:25.48: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:25.48: INF [udp] Writing UDP Packet: -> 67

2016-08-13 23:25.53: INF [ipv4] IP packet received:  (0.0.0.0 -> 255.255.255.255: proto 17, ttl 255)

2016-08-13 23:25.53: INF [udp] UDP packet received:  (68 -> 67)

2016-08-13 23:25.55: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:25.55: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:25.56: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:25.56: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:25.56: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:25.56: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:25.56: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:25.56: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:25.57: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:25.57: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:25.58: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:25.58: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:25.58: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:25.58: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:25.58: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:25.58: INF [udp] Writing UDP Packet: -> 67

2016-08-13 23:25.59: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:25.59: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:26.00: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:26.00: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:26.02: INF [ipv4] IP packet received:  (0.0.0.0 -> 255.255.255.255: proto 17, ttl 255)

2016-08-13 23:26.02: INF [udp] UDP packet received:  (68 -> 67)

2016-08-13 23:26.04: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:26.04: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:26.09: INF [ipv4] IP packet received:  (169.254.178.211 -> 224.0.0.251: proto 17, ttl 255)

2016-08-13 23:26.09: INF [udp] UDP packet received:  (5353 -> 5353)

2016-08-13 23:26.09: INF [dhcp-clientv4] DHCP: start discovery
2016-08-13 23:26.09: INF [dhcp-clientv4] Send a client broadcast packet (output_broadcast)
2016-08-13 23:26.09: INF [dhcp-clientv4] Sending DHCP broadcast (length 552)
2016-08-13 23:26.09: INF [udp] Writing UDP Packet: -> 67

Finally, they ultimately end up outputting:

xmit buffer full! next_avail:254 last_used:0

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions