[Kea-users] Problem with dhcpv6 class assignment

Thu Feb 10 16:19:49 UTC 2022

Good day,

Faced a problem with dhcpv6 server, probably it's something obvious and 
hope that somebody can point me in the right direction. I'm struggling 
to assign dhcpv6 client to a class with a final goal to select a pool 
for it.

My class definition looks like this:
     "client-classes": [
         {
                 "name": "OLT01.CHA",
                 "test": "substring(relay6[1].option[18].hex,0,6) == 
'TA5000'"
                 //"test": "relay6[1].option[18].exists"
         }
     ],

Sorry for the following long output.
In debug I see option 18 for relay[1] is 
'54:41:35:30:30:30:2f:34:2f:31:2f:34:2f:31:36' that translates to 
'TA5000/4/1/4/16', but class assignment returns only UNKNOWN:
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.packets/54654.139937539061952] 
DHCP6_QUERY_DATA duid=[00:03:00:01:84:d3:43:c8:6c:1f], tid=0x1ef087, 
packet details: l
ocalAddr=[xxxx:xxxx:1:2300::240]:0 remoteAddr=[xxxx:xxxx:1::23:135]:547
msgtype=5(RENEW), transid=0x1ef087
type=00001, len=00010: 00:03:00:01:84:d3:43:c8:6c:1f
type=00002, len=00014: 00:01:00:01:28:d2:59:de:6a:65:7e:6f:94:95
type=00003(IA_NA), len=00040: iaid=1, t1=0, t2=0,
options:
   type=00005(IAADDR), len=00024: address=xxxx:xxxx:8006:7::12, 
preferred-lft=0, valid-lft=0
type=00006, len=00030: 17(uint16) 21(uint16) 22(uint16) 23(uint16) 
24(uint16) 31(uint16) 56(uint16) 64(uint16) 67(uint16) 82(uint16) 
83(uint16) 94(uint16) 95(
uint16) 96(uint16) 12(uint16)
type=00008, len=00002: 0 (uint16)
type=00025(IA_PD), len=00041: iaid=1, t1=0, t2=0,
options:
   type=00026(IAPREFIX), len=00025: prefix=xxxx:xxxx:9000:200::/56, 
preferred-lft=0, valid-lft=0
type=39(CLIENT_FQDN), flags: (N=0, O=0, S=0), domain-name='router.' 
(full)
2 relay(s):
relay[0]: msg-type=12(RELAY_FORWARD), hop-count=1,
link-address=xxxx:xxxx:1::23:135, 
peer-address=fe80::86d3:43ff:fec8:6c1f, 3 option(s)
type=00018, len=00010: 70:73:31:3a:35:33:2d:31:30:32
type=00037, len=00014: 1411 (uint32) 7073313A35332D313032 (binary)
type=00053, len=00031: 
00:02:00:00:05:83:01:35:34:3a:31:65:3a:35:36:3a:61:35:3a:39:62:3a:63:30:00:00:00:00:00:00:00
relay[1]: msg-type=12(RELAY_FORWARD), hop-count=0,
link-address=::, peer-address=fe80::86d3:43ff:fec8:6c1f, 2 option(s)
type=00018, len=00015: 54:41:35:30:30:30:2f:34:2f:31:2f:34:2f:31:36
type=00037, len=00019: 3561 (uint32) 5441353030302F342F312F342F3136 
(binary)

2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.dhcpsrv/54654.139937539061952] 
DHCPSRV_CFGMGR_SUBNET6_RELAY selected subnet xxxx:xxxx:8006:7::/64, 
because of matchin
g relay addr xxxx:xxxx:1::23:135
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.packets/54654.139937539061952] 
DHCP6_SUBNET_SELECTED duid=[00:03:00:01:84:d3:43:c8:6c:1f], 
tid=0x1ef087: the subnet w
ith ID 2 was selected for client assignments
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.packets/54654.139937539061952] 
DHCP6_SUBNET_DATA duid=[00:03:00:01:84:d3:43:c8:6c:1f], tid=0x1ef087: 
the selected sub
net details: xxxx:xxxx:8006:7::/64
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv6 
reservation for subnet id
2, identified by hwaddr=84D343C86C1F
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
identifier: hwaddr=84
D343C86C1F
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=84D343C86C1F, 
found 0 host(s)
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet 
id 2 and identif
ier hwaddr=84D343C86C1F
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv6 
reservation for subnet id
2, identified by duid=0003000184D343C86C1F
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
identifier: duid=0003
000184D343C86C1F
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier 
duid=0003000184D343C86C1F, found 0 host(s)
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.hosts/54654.139937539061952] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet 
id 2 and identifier duid=0003000184D343C86C1F
2022-02-10 10:24:17.616 DEBUG [kea-dhcp6.dhcp6/54654.139937539061952] 
DHCP6_CLASS_ASSIGNED duid=[00:03:00:01:84:d3:43:c8:6c:1f], tid=0x1ef087: 
client packet has been assigned to the following class(es): UNKNOWN

At the same time, similar config works for dhcp4 and a client gets 
assigned into the class:
     "client-classes": [
         {
                 "name": "OLT01.CHA",
                 "test": "substring(relay4[1].hex,0,6) == 'TA5000'"
         }
     ],

2022-02-10 11:01:47.182 DEBUG [kea-dhcp4.packets/55024.140194341513408] 
DHCP4_QUERY_DATA [hwtype=1 84:d3:43:c8:6c:1f], cid=[no info], 
tid=0x8d8b047b, packet d
etails: local_address=xxx.xxx.154.240:67, 
remote_address=xxx.xxx.128.4:68, msg_type=DHCPREQUEST (3), 
transid=0x8d8b047b,
options:
   type=053, len=001: 3 (uint8)
   type=055, len=011: 1(uint8) 3(uint8) 6(uint8) 12(uint8) 15(uint8) 
28(uint8) 42(uint8) 43(uint8) 120(uint8) 121(uint8) 125(uint8)
   type=057, len=002: 576 (uint16)
   type=060, len=024: "GS4227W.ONT.dslforum.org" (string)
   type=082, len=034:,
options:
     type=001, len=015: 54:41:35:30:30:30:2f:34:2f:31:2f:34:2f:31:36
     type=002, len=015: 54:41:35:30:30:30:2f:34:2f:31:2f:34:2f:31:36
2022-02-10 11:01:47.182 DEBUG [kea-dhcp4.dhcpsrv/55024.140194341513408] 
DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet xxx.xxx.128.0/23 for packet 
received by ma
tching address xxx.xxx.128.4
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.packets/55024.140194341513408] 
DHCP4_SUBNET_SELECTED [hwtype=1 84:d3:43:c8:6c:1f], cid=[no info], 
tid=0x8d8b047b: the
  subnet with ID 2 was selected for client assignments
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.packets/55024.140194341513408] 
DHCP4_SUBNET_DATA [hwtype=1 84:d3:43:c8:6c:1f], cid=[no info], 
tid=0x8d8b047b: the sel
ected subnet details: xxx.xxx.128.0/23
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 
reservation for subnet id
2, identified by hwaddr=84D343C86C1F
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
identifier: hwaddr=84
D343C86C1F
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=84D343C86C1F, 
found 0 host(s)
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet 
id 2 and identif
ier hwaddr=84D343C86C1F
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 
reservation for subnet id
2, identified by circuit-id=5441353030302F342F312F342F3136
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using 
identifier: circuit-i
d=5441353030302F342F312F342F3136
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier 
circuit-id=5441353030302F342F312F342
F3136, found 0 host(s)
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.hosts/55024.140194341513408] 
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet 
id 2 and identif
ier circuit-id=5441353030302F342F312F342F3136
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.dhcp4/55024.140194341513408] 
DHCP4_CLASS_ASSIGNED [hwtype=1 84:d3:43:c8:6c:1f], cid=[no info], 
tid=0x8d8b047b: client
  packet has been assigned to the following class(es): UNKNOWN
2022-02-10 11:01:47.183 DEBUG [kea-dhcp4.dhcp4/55024.140194341513408] 
DHCP4_CLASS_ASSIGNED [hwtype=1 84:d3:43:c8:6c:1f], cid=[no info], 
tid=0x8d8b047b: client
  packet has been assigned to the following class(es): ALL, 
VENDOR_CLASS_GS4227W.ONT.dslforum.org, OLT01.CHA, UNKNOWN

I'd appreciate if smb could suggest where is my mistake.

And another question is about logger config. I saw in docs that 
kea-dhcp6.eval logger should be used. Currently I have:
     "loggers": [
     {
         "name": "kea-dhcp6",
         "output_options": [
             {
                  "output": "/var/log/kea-dhcp6.log",
                 "pattern": "%D{%Y-%m-%d %H:%M:%S.%q} %-5p [%c/%i.%t] 
%m\n",
                 "maxsize": 1048576,
                 "maxver": 8
             }
         ],
         "severity": "DEBUG",
         "debuglevel": 99
     }
I don't see anything with .eval in the log, should I enable it 
explicitly and what parameters should I specify in this case?

Kind regards,
Andrey