[Dnsmasq-discuss] logging DHCPDISCOVER

Fri Feb 10 22:17:51 UTC 2023

If you set the log-dhcp option in the dnsmasq config, it will log all 
the options being sent to the client, which should include a copy of the 
vendor-class received from the client.

Cheers,

Simon.

On 09/02/2023 20:54, Carl Karsten wrote:
> I want to gather stats on how often I don't get a 2nd DHCPDISCOVER.
> my plan is to log for a day, and then parse/analyze the log.
> 
> I could use some help creating the log.
> I think I want to log
> Vendor-Class (60), length 32: "PXEClient:Arch:00000:UNDI:002001"
> as that seems to be how I can tell if this is the first or 2nd dhcp.
> 
> details:
> 
> I have 10 raspi pi net booting
> server is dnsmasq which is working fine.
> 
> the pi's closed source bootcode.bin does dhcp and requests/gets the kernel:
> 
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPDISCOVER(eth-local) b8:27:eb:86:39:63
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPOFFER(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: file
> /srv/tftp/bootsig.bin not found
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: sent
> /srv/tftp/bootcode.bin to 10.21.0.136
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPDISCOVER(eth-local) b8:27:eb:86:39:63
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPOFFER(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: error 0 Early
> terminate received from 10.21.0.136
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: failed sending
> /srv/tftp/80863963/start.elf to 10.21.0.136
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: file
> /srv/tftp/80863963/autoboot.txt not found
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: error 0 Early
> terminate received from 10.21.0.136
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: failed sending
> /srv/tftp/80863963/start.elf to 10.21.0.136
> Feb  9 14:47:59 rpi-cb-1f-f7 dnsmasq-tftp[21125]: sent
> /srv/tftp/80863963/config.txt to 10.21.0.136
> 
> Feb  9 14:57:50 rpi-cb-1f-f7 dnsmasq-tftp[21125]: sent
> /srv/tftp/80863963/kernel8.img to 10.21.0.136
> Feb  9 14:58:08 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPDISCOVER(eth-local) b8:27:eb:86:39:63
> Feb  9 14:58:08 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPOFFER(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:08 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPREQUEST(eth-local) 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:08 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPACK(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63 pi36
> 
> Feb  9 14:58:10 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPDISCOVER(eth-local) b8:27:eb:86:39:63
> Feb  9 14:58:10 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPOFFER(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:10 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPREQUEST(eth-local) 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:10 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPACK(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63 pi36
> Feb  9 14:58:10 rpi-cb-1f-f7 rpc.mountd[22860]: authenticated mount
> request from 10.21.0.136:936 for /srv/nfs/rpi/bullseye/root
> (/srv/nfs/rpi/bullseye/root)
> Feb  9 14:58:24 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPDISCOVER(eth-local) b8:27:eb:86:39:63
> Feb  9 14:58:24 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPOFFER(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:24 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPREQUEST(eth-local) 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:24 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPACK(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63 pi36
> 
> Feb  9 14:58:27 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPDISCOVER(eth-local) b8:27:eb:86:39:63
> Feb  9 14:58:27 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPOFFER(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:27 rpi-cb-1f-f7 dnsmasq-dhcp[21125]:
> DHCPREQUEST(eth-local) 10.21.0.136 b8:27:eb:86:39:63
> Feb  9 14:58:27 rpi-cb-1f-f7 dnsmasq-dhcp[21125]: DHCPACK(eth-local)
> 10.21.0.136 b8:27:eb:86:39:63 pi36
> Feb  9 14:58:30 rpi-cb-1f-f7 rpc.mountd[22860]: authenticated mount
> request from 10.21.0.136:733 for /srv/nfs/rpi/bullseye/boot
> (/srv/nfs/rpi/bullseye/boot)
> 
> serial console on the pi:
> 
> Raspberry Pi Bootcode
> Read File: config.txt, 2428
> Read File: start.elf, 2975104 (bytes)
> Read File: fixup.dat, 7265 (bytes)
> MESS:00:00:21.012905:0: brfs: File read: /mfs/sd/config.txt
> 
> MESS:00:00:48.308603:0: brfs: File read: /mfs/sd/kernel8.img
> MESS:00:00:48.312568:0: Loaded 'kernel8.img' to 0x80000 size 0x7d0a2c
> MESS:00:00:50.482131:0: Kernel relocated to 0x200000
> MESS:00:00:50.485400:0: Device tree loaded to 0x2e718600 (size 0x89ba)
> MESS:00:00:50.494040:0: uart: Set PL011 baud rate to 103448.300000 Hz
> MESS:00:00:50.500331:0: uart: Baud rate change done...
> MESS:00:00:50.503764:0: uart: Baud rate change done...
> [    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
> [   15.177883] Run /init as init process
> Begin: Running /scripts/nfs-premount ... done.
> IP-Config: eth0 hardware address b8:27:eb:86:39:63 mtu 1500 DHCP
> IP-Config: eth0 complete (dhcp from 10.21.0.1):
>   address: 10.21.0.136      broadcast: 10.21.0.255      netmask:
> 255.255.255.0
> 
> except 'sometimes' a pi will load the kernel, but instead of
> executing, it gets stuck and the serial console shows:
> 
> MESS:00:00:48.312568:0: Loaded 'kernel8.img' to 0x80000 size 0x7d0a2c
> MESS:00:01:11.nnn:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not
> defined
> MESS:00:01:15.nnn:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not
> defined
> MESS:00:01:22.nnn:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not
> defined
> 
> The kernel never runs, so it never does its dhcp.
> 
> I can programmatically power cycle each pi.
> I want to power cycle them over and over for 12 hours and look for
> patterns of how often and wich one's fail to boot the kernel.
> 
> Given physical constraints, it isn't easy to connect the serial console to each.
> 
> thus my plan a dnsmasq hook that logs something useful
> 
> I'm hoping someone has already done something similar that I can make
> use of.  Or give me direction on what the easy way to do this is.
> 
> If someone wants more details on the logs I posted, I'm happy to indulge.
> 
> 
> --
> Carl K
> 
> _______________________________________________
> Dnsmasq-discuss mailing list
> Dnsmasq-discuss at lists.thekelleys.org.uk
> https://lists.thekelleys.org.uk/cgi-bin/mailman/listinfo/dnsmasq-discuss
> 