[Kea-users] client not getting ip

Bill Schoolfield bill at billmax.com
Wed Mar 25 20:12:34 UTC 2020 

Hi

First off, I'm a developer, not a network guy so bear with me please. We 
have setup a test lab to mimic the eventual production env where there 
is meant to be a single DHCP server receiving requests from relays. 
First test didn't work. Below is most of the log as it pertains to the 
request.

 From what I can tell, things go south after the OFFER is made. Is that 
correct? Perhaps the offer is not making back to the client's laptop? Is 
this a relay issue?

Bill

Mar 25 19:35:12 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.alloc-engine] 
ALLOC_ENGINE_V4_RECLAIMED_LEASES_DELETE begin deletion of reclaimed 
leases expired more than 3600 seconds ago
Mar 25 19:35:12 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_MYSQL_DELETE_EXPIRED_RECLAIMED4 deleting reclaimed IPv4 leases 
that expired more than 3600 seconds ago
Mar 25 19:35:12 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_MYSQL_DELETED_EXPIRED_RECLAIMED deleted 0 reclaimed leases from 
the database
Mar 25 19:35:12 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.alloc-engine] 
ALLOC_ENGINE_V4_RECLAIMED_LEASES_DELETE_COMPLETE successfully deleted 0 
expired-reclaimed leases
Mar 25 19:35:12 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_TIMERMGR_START_TIMER starting timer: flush-reclaimed-leases
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.packets] 
DHCP4_BUFFER_RECEIVED received buffer from 50.30.96.97:67 to 
162.210.231.226:67 over interface eth0
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.options] 
DHCP4_BUFFER_UNPACK parsing buffer received from 50.30.96.97 to 
162.210.231.226 over interface eth0
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.packets] 
DHCP4_PACKET_RECEIVED [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: DHCPDISCOVER (type 1) 
received from 50.30.96.97 to 162.210.231.226 on interface eth0
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.packets] 
DHCP4_QUERY_DATA [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d, packet details: 
local_address=162.210.231.226:67, remote_address=50.30.96.97:67, 
msg_type=DHCPDISCOVER (1), transid=0x12c6749d,#012options:#012  
type=012, len=012: "Craig-Laptop" (string)#012  type=053, len=001: 1 
(uint8)#012 type=055, len=014: 1(uint8) 3(uint8) 6(uint8) 15(uint8) 
31(uint8) 33(uint8) 43(uint8) 44(uint8) 46(uint8) 47(uint8) 119(uint8) 
121(uint8) 249(uint8) 252(uint8)#012  type=060, len=008: "MSFT 5.0" 
(string)#012  type=061, len=007: 01:50:9a:4c:c7:ec:b2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet 100.64.58.0/24 for packet 
received by matching address 100.64.58.1
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.packets] 
DHCP4_SUBNET_SELECTED [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: the subnet with ID 1 was 
selected for client assignments
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.packets] 
DHCP4_SUBNET_DATA [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: the selected subnet details: 
100.64.58.0/24
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 
reservation for subnet id 1, identified by hwaddr=509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
identifier: hwaddr=509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=509A4CC7ECB2, 
found 0 host(s)
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet 
id 1 and identifier hwaddr=509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER get one host with IPv4 
reservation for subnet id 1, identified by hwaddr=509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER_NULL host not found using 
subnet id 1 and identifier hwaddr=509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 
reservation for subnet id 1, identified by client-id=01509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
identifier: client-id=01509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier 
client-id=01509A4CC7ECB2, found 0 host(s)
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet 
id 1 and identifier client-id=01509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER get one host with IPv4 
reservation for subnet id 1, identified by client-id=01509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER_NULL host not found using 
subnet id 1 and identifier client-id=01509A4CC7ECB2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcp4] 
DHCP4_CLASS_ASSIGNED [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: client packet has been 
assigned to the following class(es): UNKNOWN
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcp4] 
DHCP4_CLASS_ASSIGNED [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: client packet has been 
assigned to the following class(es): ALL, VENDOR_CLASS_MSFT 5.0, UNKNOWN
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.ddns] 
DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: processing client's Hostname 
option
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.ddns] 
DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: client sent Hostname option: 
Craig-Laptop
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.ddns] 
DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: client sent Hostname option: 
Craig-Laptop
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.ddns] 
DHCP4_RESPONSE_HOSTNAME_DATA [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: including Hostname option in 
the server's response: Craig-Laptop
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_MYSQL_GET_CLIENTID obtaining IPv4 leases for client ID 
01:50:9a:4c:c7:ec:b2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_MYSQL_GET_HWADDR obtaining IPv4 leases for hardware address 
hwtype=1 50:9a:4c:c7:ec:b2
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.alloc-engine] 
ALLOC_ENGINE_V4_OFFER_NEW_LEASE allocation engine will try to offer new 
lease to the client [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for 
subnet id 1 and IPv4 address 100.64.58.9
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ALL_ADDRESS4 get all hosts with reservations for IPv4 
address 100.64.58.9
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 100.64.58.9, found 0 host(s)
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 
1 and address 100.64.58.9
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.hosts] 
HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate sources for 
host using subnet id 1 and address 100.64.58.9
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_MYSQL_GET_ADDR4 obtaining IPv4 lease for address 100.64.58.9
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.dhcpsrv] 
DHCPSRV_MYSQL_GET_ADDR4 obtaining IPv4 lease for address 100.64.58.9
Mar 25 19:35:13 dhcp1 kea-dhcp4: INFO  [kea-dhcp4.leases] 
DHCP4_LEASE_ADVERT [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: lease 100.64.58.9 will be 
advertised
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.options] 
DHCP4_PACKET_PACK [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: preparing on-wire format of 
the packet to be sent
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.packets] 
DHCP4_PACKET_SEND [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: trying to send packet 
DHCPOFFER (type 2) from 162.210.231.226:67 to 100.64.58.1:67 on 
interface eth0
Mar 25 19:35:13 dhcp1 kea-dhcp4: DEBUG [kea-dhcp4.packets] 
DHCP4_RESPONSE_DATA [hwtype=1 50:9a:4c:c7:ec:b2], 
cid=[01:50:9a:4c:c7:ec:b2], tid=0x12c6749d: responding with packet 
DHCPOFFER (type 2), packet details: local_address=162.210.231.226:67, 
remote_address=100.64.58.1:67, msg_type=DHCPOFFER (2), 
transid=0x12c6749d,#012options:#012 type=001, len=004: 4294967040 
(uint32)#012  type=006, len=012: 50.30.96.101 8.8.8.8 50.30.96.103#012  
type=012, len=012: "Craig-Laptop" (string)#012  type=051, len=004: 3600 
(uint32)#012  type=053, len=001: 2 (uint8)#012  type=054, len=004: 
162.210.231.226#012  type=061, len=007: 01:50:9a:4c:c7:ec:b2

More information about the Kea-users mailing list