DEBUG DHCP4_CLASS_ASSIGNED fails to log properly in kea-dhcp4.dhcp4 with shared-networks
If a subnet is part of a shared-networks definition, then classes assigned by reservations are not logged in the DHCP4_CLASS_ASSIGNED messages. This simple configuration:
{
"Dhcp4": {
"interfaces-config": {
"interfaces": [ "ens256" ]
},
"lease-database": {
"type": "memfile",
"persist": false
},
"loggers": [
{
"name": "kea-dhcp4",
"output_options": [
{
"output": "/tmp/all-dhcp4.log"
}
],
"severity": "DEBUG",
"debuglevel": 99
}
],
"client-classes": [
{
"name": "someclass",
"option-data": [
{
"name": "routers",
"data": "10.1.2.1"
}
]
}
],
"shared-networks": [
{
"name": "some-shared-network",
"subnet4": [
{
"subnet": "10.1.2.0/24",
"reservations": [
{
"client-classes": [
"someclass"
],
"hw-address": "00:0c:01:02:03:04",
"ip-address": "10.1.2.133",
}
]
}
]
}
]
}
}
results in logs like this:
2023-06-06 12:36:47.547 DEBUG [kea-dhcp4.dhcp4/4418.281472760196992] DHCP4_CLASS_ASSIGNED [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x2b: client packet has been assigned to the following class(es): KNOWN
2023-06-06 12:36:47.547 DEBUG [kea-dhcp4.dhcp4/4418.281472760196992] DHCP4_CLASS_ASSIGNED [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x2b: client packet has been assigned to the following class(es): ALL, KNOWN
even though the client is added to the class as evidenced by the presence of the 10.1.2.1 routers option in the packet:
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.dhcp4/4553.281472785596288] DHCP4_CLASS_ASSIGNED [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: client packet has been assigned to the following class(es): KNOWN
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.dhcp4/4553.281472785596288] DHCP4_CLASS_ASSIGNED [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: client packet has been assigned to the following class(es): ALL, KNOWN
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.ddns/4553.281472785596288] DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: processing client's Hostname option
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.dhcpsrv/4553.281472785596288] DHCPSRV_MEMFILE_GET_CLIENTID obtaining IPv4 leases for client ID 01:00:0c:01:02:03:04
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.hosts/4553.281472785596288] HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for subnet id 1 and IPv4 address 10.1.2.133
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.hosts/4553.281472785596288] HOSTS_CFG_GET_ALL_ADDRESS4 get all hosts with reservations for IPv4 address 10.1.2.133
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.hosts/4553.281472785596288] HOSTS_CFG_GET_ALL_ADDRESS4_HOST using address 10.1.2.133 found host: hwaddr=000C01020304 ipv4_subnet_id=1 hostname=(empty) ipv4_reservation=10.1.2.133 siaddr=(no) sname=(empty) file=(empty) key=(empty) ipv6_reservations=(none) dhcp4_class0=someclass
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.hosts/4553.281472785596288] HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 10.1.2.133, found 1 host(s)
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.hosts/4553.281472785596288] HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_HOST using subnet id 1 and address 10.1.2.133, found host: hwaddr=000C01020304 ipv4_subnet_id=1 hostname=(empty) ipv4_reservation=10.1.2.133 siaddr=(no) sname=(empty) file=(empty) key=(empty) ipv6_reservations=(none) dhcp4_class0=someclass
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.dhcpsrv/4553.281472785596288] DHCPSRV_MEMFILE_GET_ADDR4 obtaining IPv4 lease for address 10.1.2.133
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.alloc-engine/4553.281472785596288] ALLOC_ENGINE_V4_REQUEST_EXTEND_LEASE [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: extending lifetime of the lease for address 10.1.2.133
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.dhcpsrv/4553.281472785596288] DHCPSRV_MEMFILE_UPDATE_ADDR4 updating IPv4 lease for address 10.1.2.133
2023-06-06 12:57:39.715 INFO [kea-dhcp4.leases/4553.281472785596288] DHCP4_LEASE_ALLOC [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: lease 10.1.2.133 has been allocated for 7200 seconds
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.options/4553.281472785596288] DHCP4_PACKET_PACK [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: preparing on-wire format of the packet to be sent
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.packets/4553.281472785596288] DHCP4_PACKET_SEND [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: trying to send packet DHCPACK (type 5) from 10.1.2.2:67 to 10.1.2.6:67 on interface ens256
2023-06-06 12:57:39.715 DEBUG [kea-dhcp4.packets/4553.281472785596288] DHCP4_RESPONSE_DATA [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0x189: responding with packet DHCPACK (type 5), packet details: local_address=10.1.2.2:67, remote_address=10.1.2.6:67, msg_type=DHCPACK (5), transid=0x189,
options:
type=001, len=004: 4294967040 (uint32)
type=003, len=004: 10.1.2.1
type=051, len=004: 7200 (uint32)
type=053, len=001: 5 (uint8)
type=054, len=004: 10.1.2.2
type=061, len=007: 01:00:0c:01:02:03:04
being present in the DHCPACK
Remove the shared-networks as shown:
{
"Dhcp4": {
"interfaces-config": {
"interfaces": [ "ens256" ]
},
"lease-database": {
"type": "memfile",
"persist": false
},
"loggers": [
{
"name": "kea-dhcp4",
"output_options": [
{
"output": "/tmp/all-dhcp4.log"
}
],
"severity": "DEBUG",
"debuglevel": 99
}
],
"client-classes": [
{
"name": "someclass",
"option-data": [
{
"name": "routers",
"data": "10.1.2.1"
}
]
}
],
"subnet4": [
{
"subnet": "10.1.2.0/24",
"reservations": [
{
"client-classes": [
"someclass"
],
"hw-address": "00:0c:01:02:03:04",
"ip-address": "10.1.2.133",
}
]
}
]
}
}
And the log notes that the client has been added to 'someclass':
2023-06-06 12:54:14.715 DEBUG [kea-dhcp4.dhcp4/4512.281473095200640] DHCP4_CLASS_ASSIGNED [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0xbc: client packet has been assigned to the following class(es): KNOWN
2023-06-06 12:54:14.715 DEBUG [kea-dhcp4.dhcp4/4512.281473095200640] DHCP4_CLASS_ASSIGNED [hwtype=1 00:0c:01:02:03:04], cid=[01:00:0c:01:02:03:04], tid=0xbc: client packet has been assigned to the following class(es): ALL, someclass, KNOWN
Edited by Darren Ankney