[Kea-users] Problem with dhcpv6 class assignment

Thu Feb 10 19:15:22 UTC 2022

Actually I found myself that expression is evaluated correctly, but the 
class isn't assigned:
2022-02-10 14:01:29.229 DEBUG [kea-dhcp6.eval/16097.140631291214016] 
EVAL_DEBUG_OPTION Pushing option 18 with value 
0x5441353030302F322F312F342F38
2022-02-10 14:01:29.229 DEBUG [kea-dhcp6.eval/16097.140631291214016] 
EVAL_DEBUG_STRING Pushing text string '0'
2022-02-10 14:01:29.229 DEBUG [kea-dhcp6.eval/16097.140631291214016] 
EVAL_DEBUG_STRING Pushing text string '6'
2022-02-10 14:01:29.229 DEBUG [kea-dhcp6.eval/16097.140631291214016] 
EVAL_DEBUG_SUBSTRING Popping length 6, start 0, string 
0x5441353030302F322F312F342F38 pus
hing result 0x544135303030
2022-02-10 14:01:29.229 DEBUG [kea-dhcp6.eval/16097.140631291214016] 
EVAL_DEBUG_STRING Pushing text string 'TA5000'
2022-02-10 14:01:29.229 DEBUG [kea-dhcp6.eval/16097.140631291214016] 
EVAL_DEBUG_EQUAL Popping 0x544135303030 and 0x544135303030 pushing 
result 'true'
2022-02-10 14:01:29.229 INFO  [kea-dhcp6.dhcp6/16097.140631291214016] 
EVAL_RESULT Expression OLT01.CHA evaluated to 1

2022-02-10 14:01:29.229 DEBUG [kea-dhcp6.dhcp6/16097.140631291214016] 
DHCP6_CLASS_ASSIGNED duid=[00:03:00:01:3c:90:66:8a:db:f0], tid=0x4802b5: 
client packet has been assigned to the following class(es): UNKNOWN

So, why it couldn't assign the class if the test is evaluated 
successfully?

In kea-dhcp4.log there are two lines with classes, first with only 
UNKNOWN and the next one with classes as needed. In kea-dhcp6.log there 
is only one line with UNKNOWN class. Any clue appreciated.

Andrey Kostin писал(а) 2022-02-10 11:19:
> 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