Open sebastiaopamplona opened 7 months ago
According to RFC2131 section 2it is defined as follows:
Filled in by client, seconds elapsed since client began address acquisition or renewal process.
It's not used anywhere in this library, as it's always set to 0. I don't think it's related to the issue you're seeing. Do you see lost packets with tcpdump?
Thanks for the swift reply :)
So that makes a lot of sense since the client is sending another DHCPDISCOVER 4 seconds after the first DHCPACK.
Do you have any guess on what might be causing the client to send the DHCPDISCOVER again after 4 seconds? Could it be that the DHCPACK is not reaching the client?
Could it be that the DHCPACK is not reaching the client?
Usually, yes, it depends on the client. You should verify that the server is sending the reply and that it's making its way back to the client. Using tcpdump on the server should be enough
Using tcpdump on the server should be enough
Thanks for the tip; I re-ran my tests and the ACK that I suspect is being dropped is showing on the pcap from tcpdump on the server:
I knew which IP was going to be leased to which mac, so I ran ping on the side to see when the IP is actually picked up (because I know eventually it will be picked up):
2024-04-20T13:28:33,304819126+00:00 64 bytes from 10.175.137.17: icmp_seq=304 ttl=64 time=0.101 ms
2024-04-20T13:28:32,280775642+00:00 64 bytes from 10.175.137.17: icmp_seq=303 ttl=64 time=0.120 ms
2024-04-20T13:28:31,256329346+00:00 64 bytes from 10.175.137.17: icmp_seq=302 ttl=64 time=0.096 ms
2024-04-20T13:28:30,232135206+00:00 64 bytes from 10.175.137.17: icmp_seq=301 ttl=64 time=0.093 ms
2024-04-20T13:28:29,208345975+00:00 64 bytes from 10.175.137.17: icmp_seq=300 ttl=64 time=0.096 ms
2024-04-20T13:28:28,185493237+00:00 64 bytes from 10.175.137.17: icmp_seq=299 ttl=64 time=0.109 ms
2024-04-20T13:28:16,925263459+00:00 From 10.175.136.253 icmp_seq=287 Destination Host Unreachable
2024-04-20T13:28:16,923468680+00:00 From 10.175.136.253 icmp_seq=286 Destination Host Unreachable
2024-04-20T13:28:16,921300666+00:00 From 10.175.136.253 icmp_seq=285 Destination Host Unreachable
2024-04-20T13:28:13,856348517+00:00 From 10.175.136.253 icmp_seq=284 Destination Host Unreachable
2024-04-20T13:28:13,854944842+00:00 From 10.175.136.253 icmp_seq=283 Destination Host Unreachable
2024-04-20T13:28:13,853319968+00:00 From 10.175.136.253 icmp_seq=282 Destination Host Unreachable
Around the timestamp of the first ACK (13:28:19) the IP is still not pingable and the client sends another DISCOVER (let's call this retry DISCOVER) 4 seconds after the last message (DHCPREQUEST at 13:28:19).
When I had a look at the logs of my DHCP server, I noticed retry DISCOVER had num seconds: 4
:
2024-04-20T13:43:11.31803562Z -->> DHCPACK 0.0.0.0 01:01:01:01:01:01 10.175.137.17 renewal DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x2d878c1f | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:43:11.315012534Z <<-- DHCPREQUEST 10.175.137.17 01:01:01:01:01:01 <nil> DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x2d878c1f | num seconds: 0 | flags: Unicast (0x00) | client IP: 10.175.137.17 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: DHCP Message Type: REQUEST
2024-04-20T13:33:37.314792609Z -->> DHCPACK 0.0.0.0 01:01:01:01:01:01 10.175.137.17 renewal DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x2d878c1f | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:33:37.31196775Z <<-- DHCPREQUEST 0.0.0.0 01:01:01:01:01:01 10.175.137.17 DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x2d878c1f | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Requested IP Address: 10.175.137.17
2024-04-20T13:33:37.311804205Z -->> DHCPOFFER 0.0.0.0 01:01:01:01:01:01 10.175.137.17 DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x2d878c1f | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:33:37.310294661Z <<-- DHCPDISCOVER 0.0.0.0 01:01:01:01:01:01 DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x2d878c1f | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: DHCP Message Type: DISCOVER
2024-04-20T13:28:28.140622434Z -->> DHCPACK 0.0.0.0 01:01:01:01:01:01 10.175.137.17 renewal DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x45eba95d | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:28:28.137630163Z <<-- DHCPREQUEST 0.0.0.0 01:01:01:01:01:01 10.175.137.17 DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x45eba95d | num seconds: 18 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Requested IP Address: 10.175.137.17
2024-04-20T13:28:24.623792011Z -->> DHCPOFFER 0.0.0.0 01:01:01:01:01:01 10.175.137.17 DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x45eba95d | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:28:24.622407292Z <<-- DHCPDISCOVER 0.0.0.0 01:01:01:01:01:01 DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x45eba95d | num seconds: 10 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: DHCP Message Type: DISCOVER
2024-04-20T13:28:22.895196511Z -->> DHCPOFFER 0.0.0.0 01:01:01:01:01:01 10.175.137.17 DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x45eba95d | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
(!2) (retry DISCOVER) num seconds is 4, which is the time since the last message (DHCPREQUEST at 13:28:19)
2024-04-20T13:28:22.893984593Z <<-- DHCPDISCOVER 0.0.0.0 01:01:01:01:01:01 DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0x45eba95d | num seconds: 4 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: DHCP Message Type: DISCOVER
(!1) i suspect this DHCPACK did not reach the client
2024-04-20T13:28:19.077922738Z -->> DHCPACK 0.0.0.0 01:01:01:01:01:01 10.175.137.17 renewal DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0xc3bf6768 | num seconds: 0 | flags: Broadcast (0x8000) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:28:19.074780638Z <<-- DHCPREQUEST 0.0.0.0 01:01:01:01:01:01 10.175.137.17 DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0xc3bf6768 | num seconds: 0 | flags: Broadcast (0x8000) | client IP: 0.0.0.0 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Requested IP Address: 10.175.137.17
2024-04-20T13:28:15.518372064Z -->> DHCPOFFER 0.0.0.0 01:01:01:01:01:01 10.175.137.17 DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0xc3bf6768 | num seconds: 0 | flags: Broadcast (0x8000) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:28:15.517139138Z <<-- DHCPDISCOVER 0.0.0.0 01:01:01:01:01:01 DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0xc3bf6768 | num seconds: 0 | flags: Broadcast (0x8000) | client IP: 0.0.0.0 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: DHCP Message Type: DISCOVER
2024-04-20T13:23:07.595853391Z -->> DHCPACK 0.0.0.0 01:01:01:01:01:01 10.175.137.17 renewal DHCPv4 Message | opcode: BootReply | hwtype: Ethernet | hopcount: 0 | transaction ID: 0xa43b020b | num seconds: 0 | flags: Unicast (0x00) | client IP: 0.0.0.0 | your IP: 10.175.137.17 | server IP: 10.175.136.253 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: Subnet Mask: fffff800
2024-04-20T13:23:07.592484438Z <<-- DHCPREQUEST 10.175.137.17 01:01:01:01:01:01 <nil> DHCPv4 Message | opcode: BootRequest | hwtype: Ethernet | hopcount: 0 | transaction ID: 0xa43b020b | num seconds: 0 | flags: Unicast (0x00) | client IP: 10.175.137.17 | your IP: 0.0.0.0 | server IP: 0.0.0.0 | gateway IP: 0.0.0.0 | client MAC: 01:01:01:01:01:01 | server hostname: | bootfile name: options: DHCP Message Type: REQUEST
It looks to me like this num seconds: 4
matches the time between the last DHCP message the client received.
Could it be that my only option is to figure out a way to run tcpdump on the client, to make sure the ACK got there? Or is there a flaw in my analysis 🤔
https://github.com/insomniacslk/dhcp/blob/f1cffa2c0c49cf0a0dddde82d51ff4e529a49f73/dhcpv4/dhcpv4.go#L64
By reading the DHCP RFC, I can't figure out what the field NumSeconds stands for.
I'm super interested in knowing this because I'm facing some flaky issues where with high load, it seems some UDP packets are dropped (my theory), by looking at the DHCP logs (I wrote a wrapper around this lib):