[Kea-users] ipv4 reclamation from dhcp4 server
John Gammon
john.gammon at forkeddeer.com
Thu Jul 14 19:17:42 UTC 2022
Good afternoon, all.
I have a air-gapped BENCHTEST system (6.6.6.0/28) comprised with a router (6.6.6.1) a dhcp4, dhcp_dns, and isc-stork-server (6.6.6.2) installed and active. The lease times and reclamation times are short for testing purposes within our environment. I am concerned with the DORA occuring for the Windows node "staking1," an offering is made with the IPv4Addr 6.6.6.6 (which is within the scope), but IPv4a remains unassigned. Unsure of what the conflict is but the message indicates the ALLOC_ENGINE_V4_LEASE_RECLAMATION_FAILED lets me know that the reclamation configuration is not working.
Reference the kea-dhcp4-bench.conf
----------------------------------------------------------------------------------------------
<...snip...>8
// Addresses will be assigned with a lifetime of 100 seconds.
// 86400 seconds = 1 day
// 2592000 seconds = 30 days
"valid-lifetime": 100,
// Renew and rebind timers are commented out. This implies that options
// 58 and 59 will not be sent to the client. In this case it is up to
// the client to pick the timer values according to RFC2131. Uncomment the
// timers to send these options to the client.
//// 20220511...jpg...changed values to match 'valid-lifetime' ratios...
# "renew-timer": 21600,
# "rebind-timer": 43200,
"renew-timer": 10,
"rebind-timer": 20,
// Setup reclamation of the expired leases and leases affinity,
"expired-leases-processing": {
"reclaim-timer-wait-time": 5,
"flush-reclaimed-timer-wait-time": 0,
"hold-reclaimed-time": 1,
"max-reclaim-leases": 0,
"max-reclaim-time": 0,
"unwarned-reclaim-cycles": 2
},
8<...snip...>8
---------------------------------------------------------------------------------------------
Reference the clip below from the kea-dhcp4-bench.log.
---------------------------------------------------------------------------------------------
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_PACKET_RECEIVED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: DHCPDISCOVER (type 1) received from 0.0.0.0 to 255.255.255.255 on interface eno1
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_QUERY_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6, packet details: local_address=255.255.255.255:67, remote_address=0.0.0.0:68, msg_type=DHCPDISCOVER (1), transid=0x3e1920d6,
options:
type=012, len=008: "staking1" (string)
type=053, len=001: 1 (uint8)
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)
type=060, len=008: "MSFT 5.0" (string)
type=061, len=007: 01:e0:db:55:ea:b2:e9
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.dhcpsrv/2626.140375353876096] DHCPSRV_CFGMGR_SUBNET4_IFACE selected subnet 6.6.6.0/28 for packet received over interface eno1
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_SUBNET_SELECTED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: the subnet with ID 6066 was selected for client assignments
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_SUBNET_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: the selected subnet details: 6.6.6.0/28
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 6066, identified by hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using identifier: hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=E0DB55EAB2E9, found 0 host(s)
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 6066 and identifier hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.467 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 6066, identified by hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 6066 and identifier hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.dhcp4/2626.140375353876096] DHCP4_CLASS_ASSIGNED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: client packet has been assigned to the following class(es): UNKNOWN
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.dhcp4/2626.140375353876096] DHCP4_CLASS_ASSIGNED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: client packet has been assigned to the following class(es): ALL, VENDOR_CLASS_MSFT 5.0, UNKNOWN
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.ddns/2626.140375353876096] DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: processing client's Hostname option
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.ddns/2626.140375353876096] DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: client sent Hostname option: staking1
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.ddns/2626.140375353876096] DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: client sent Hostname option: staking1
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.ddns/2626.140375353876096] DHCP4_RESPONSE_HOSTNAME_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: including Hostname option in the server's response: staking1.forkeddeerconnect.com
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.dhcpsrv/2626.140375353876096] DHCPSRV_PGSQL_GET_CLIENTID obtaining IPv4 leases for client ID 01:e0:db:55:ea:b2:e9
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for subnet id 6066 and IPv4 address 6.6.6.6
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ALL_ADDRESS4 get all hosts with reservations for IPv4 address 6.6.6.6
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 6.6.6.6, found 0 host(s)
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 6066 and address 6.6.6.6
2022-07-14 09:31:55.468 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate sources for host using subnet id 6066 and address 6.6.6.6
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.alloc-engine/2626.140375353876096] ALLOC_ENGINE_V4_OFFER_EXISTING_LEASE allocation engine will try to offer existing lease to the client [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6
2022-07-14 09:31:55.469 INFO [kea-dhcp4.leases/2626.140375353876096] DHCP4_LEASE_ADVERT [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: lease 6.6.6.6 will be advertised
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.options/2626.140375353876096] DHCP4_PACKET_PACK [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: preparing on-wire format of the packet to be sent
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_PACKET_SEND [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: trying to send packet DHCPOFFER (type 2) from 169.254.26.54:67 to 6.6.6.6:68 on interface eno1
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_RESPONSE_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: responding with packet DHCPOFFER (type 2), packet details: local_address=169.254.26.54:67, remote_address=6.6.6.6:68, msg_type=DHCPOFFER (2), transid=0x3e1920d6,
options:
type=001, len=004: 4294967280 (uint32)
type=003, len=004: 6.6.6.1
type=006, len=004: 6.6.6.2
type=012, len=030: "staking1.forkeddeerconnect.com" (string)
type=015, len=021: "forkeddeerconnect.com" (string)
type=051, len=004: 100 (uint32)
type=053, len=001: 2 (uint8)
type=054, len=004: 169.254.26.54
type=059, len=004: 10 (uint32)
type=061, len=007: 01:e0:db:55:ea:b2:e9
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_BUFFER_RECEIVED received buffer from 0.0.0.0:68 to 255.255.255.255:67 over interface eno1
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.options/2626.140375353876096] DHCP4_BUFFER_UNPACK parsing buffer received from 0.0.0.0 to 255.255.255.255 over interface eno1
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.dhcpsrv/2626.140375353876096] DHCPSRV_CFGMGR_SUBNET4_IFACE selected subnet 6.6.6.0/28 for packet received over interface eno1
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_SUBNET_SELECTED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: the subnet with ID 6066 was selected for client assignments
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_SUBNET_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: the selected subnet details: 6.6.6.0/28
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_PACKET_RECEIVED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: DHCPDISCOVER (type 1) received from 0.0.0.0 to 255.255.255.255 on interface eno1
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_QUERY_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6, packet details: local_address=255.255.255.255:67, remote_address=0.0.0.0:68, msg_type=DHCPDISCOVER (1), transid=0x3e1920d6,
options:
type=012, len=008: "staking1" (string)
type=053, len=001: 1 (uint8)
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)
type=060, len=008: "MSFT 5.0" (string)
type=061, len=007: 01:e0:db:55:ea:b2:e9
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.dhcpsrv/2626.140375353876096] DHCPSRV_CFGMGR_SUBNET4_IFACE selected subnet 6.6.6.0/28 for packet received over interface eno1
2022-07-14 09:31:55.469 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_SUBNET_SELECTED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: the subnet with ID 6066 was selected for client assignments
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.packets/2626.140375353876096] DHCP4_SUBNET_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: the selected subnet details: 6.6.6.0/28
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 6066, identified by hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using identifier: hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=E0DB55EAB2E9, found 0 host(s)
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 6066 and identifier hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 6066, identified by hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.hosts/2626.140375353876096] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 6066 and identifier hwaddr=E0DB55EAB2E9
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.dhcp4/2626.140375353876096] DHCP4_CLASS_ASSIGNED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: client packet has been assigned to the following class(es): UNKNOWN
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.dhcp4/2626.140375353876096] DHCP4_CLASS_ASSIGNED [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: client packet has been assigned to the following class(es): ALL, VENDOR_CLASS_MSFT 5.0, UNKNOWN
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.ddns/2626.140375353876096] DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: processing client's Hostname option
2022-07-14 09:31:55.470 DEBUG [kea-dhcp4.ddns/2626.140375353876096] DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 e0:db:55:ea:b2:e9], cid=[01:e0:db:55:ea:b2:e9], tid=0x3e1920d6: client sent Hostname option: staking1
---------------------------------------------------------------------------------------------
I am using a pgsql database (rel. 12) to store our leases. I am unsure why it is not locating the information in the database to delete the records and "reclaim" the IPv4 from the very small pool on our BENCHTEST environment. Any ideas or pointers? I am not as seasoned as many of you. Therefore, I welcome all comments.
Thanks,
jpg
John Gammon
Network Engineer
Forked Deer Electric Cooperative, Inc./Forked Deer Connect, LLC.
Halls, TN 38040
email: john.gammon at forkeddeer.com
John Gammon
Network Engineer
Office 731-903-4282
john.gammon at forkeddeer.com<mailto:%20john.gammon at forkeddeer.com>
[fdec logo]
1135 North Church Street
PO Box 67
Halls, TN 38040
www.forkeddeer.com
More information about the Kea-users
mailing list