[Kea-users] custom options breaking things
Jason Guy
jguy at cumulusnetworks.com
Wed Jan 30 18:12:41 UTC 2019
Hi all,
I am seeing an issue with the custom options. I have defined these in the
config, and generally they seem to work, but I am seeing in a few cases kea
indicates the option is too big.
However I know the defined is a simple string:
"option-data": [
<snip>
{
"code": 239,
"csv-format": true,
"data": "http://monster-01.rdu.cumulusnetworks.com/ztp",
"name": "cumulus-provision-url",
"space": "dhcp4"
},
<snip>
],
"option-def": [
{
"code": 239,
"name": "cumulus-provision-url",
"space": "dhcp4",
"type": "string"
},
Debugs are attached in the txt file, showing one device is getting option
239 properly, while the other is hitting the error. The DHCP option request
list appears to be the same for both clients, so I am not entirely sure
what is causing the issue for select clients.
I am working on upgrading to 1.4 or 1.5, but I would like to work around
this issue in the meantime. I found commenting out the custom option
definition does not fix the issue either.
Thanks,
Jason
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.isc.org/pipermail/kea-users/attachments/20190130/c6b92ecd/attachment.htm>
-------------- next part --------------
Working DHCPOFFER
=====================
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.packets/8334] DHCP4_PACKET_RECEIVED [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: DHCPREQUEST (type 3) received from 10.50.24.151 to 10.50.5.11 on interface eth0
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.packets/8334] DHCP4_QUERY_DATA [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519, packet details: local_address=10.50.5.11:67, remote_address=10.50.24.151:68, msg_type=DHCPREQUEST (3), transid=0x9c076519,
options:
type=012, len=031: "cumulus.rdu.cumulusnetworks.com" (string)
type=051, len=004: 7200 (uint32)
type=053, len=001: 3 (uint8)
type=055, len=014: 1(uint8) 28(uint8) 2(uint8) 3(uint8) 15(uint8) 6(uint8) 119(uint8) 12(uint8) 44(uint8) 47(uint8) 26(uint8) 121(uint8) 42(uint8) 239(uint8)
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_CFGMGR_SUBNET4_ADDR selected subnet 10.50.24.0/24 for packet received by matching address 10.50.24.151
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.packets/8334] DHCP4_SUBNET_SELECTED [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: the subnet with ID 24 was selected for client assignments
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.packets/8334] DHCP4_SUBNET_DATA [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: the selected subnet details: 10.50.24.0/24
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 24, identified by hwaddr=8CEA1B204831
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using identifier: hwaddr=8CEA1B204831
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=8CEA1B204831, found 0 host(s)
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 24 and identifier hwaddr=8CEA1B204831
2019-01-30 12:12:18.818 DEBUG [kea-dhcp4.hosts/8334] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 24, identified by hwaddr=8CEA1B204831
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.hosts/8334] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 24 and identifier hwaddr=8CEA1B204831
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.ddns/8334] DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: processing client's Hostname option
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.ddns/8334] DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: client sent Hostname option: cumulus.rdu.cumulusnetworks.com
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.ddns/8334] DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: client sent Hostname option: cumulus.rdu.cumulusnetworks.com
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.ddns/8334] DHCP4_RESPONSE_HOSTNAME_DATA [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: including Hostname option in the server's response: cumulus.rdu.cumulusnetworks.com
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_MYSQL_GET_HWADDR obtaining IPv4 leases for hardware address hwtype=1 8c:ea:1b:20:48:31
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for subnet id 24 and IPv4 address 10.50.24.151
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ALL_ADDRESS4 get all hosts with reservations for IPv4 address 10.50.24.151
2019-01-30 12:12:18.819 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 10.50.24.151, found 0 host(s)
2019-01-30 12:12:18.820 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 24 and address 10.50.24.151
2019-01-30 12:12:18.820 DEBUG [kea-dhcp4.hosts/8334] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate source for host using subnet id 24 and address 10.50.24.151
2019-01-30 12:12:18.820 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_MYSQL_GET_ADDR4 obtaining IPv4 lease for address 10.50.24.151
2019-01-30 12:12:18.820 DEBUG [kea-dhcp4.alloc-engine/8334] ALLOC_ENGINE_V4_REQUEST_EXTEND_LEASE [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: extending lifetime of the lease for address 10.50.24.151
2019-01-30 12:12:18.820 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_MYSQL_UPDATE_ADDR4 updating IPv4 lease for address 10.50.24.151
2019-01-30 12:12:18.829 INFO [kea-dhcp4.leases/8334] DHCP4_LEASE_ALLOC [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: lease 10.50.24.151 has been allocated
2019-01-30 12:12:18.829 DEBUG [kea-dhcp4.dhcp4/8334] DHCP4_CLIENTID_IGNORED_FOR_LEASES [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: not using client identifier for lease allocation for subnet 24
2019-01-30 12:12:18.829 DEBUG [kea-dhcp4.ddns/8334] DHCP4_NCR_CREATE [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: DDNS updates enabled, therefore sending name change requests
2019-01-30 12:12:18.829 DEBUG [kea-dhcp4.options/8334] DHCP4_PACKET_PACK [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: preparing on-wire format of the packet to be sent
2019-01-30 12:12:18.829 DEBUG [kea-dhcp4.packets/8334] DHCP4_PACKET_SEND [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: trying to send packet DHCPACK (type 5) from 10.50.5.11:67 to 10.50.24.151:68 on interface eth0
2019-01-30 12:12:18.829 DEBUG [kea-dhcp4.packets/8334] DHCP4_RESPONSE_DATA [hwtype=1 8c:ea:1b:20:48:31], cid=[no info], tid=0x9c076519: responding with packet DHCPACK (type 5), packet details: local_address=10.50.5.11:67, remote_address=10.50.24.151:68, msg_type=DHCPACK (5), transid=0x9c076519,
options:
type=001, len=004: 4294967040 (uint32)
type=003, len=004: 10.50.24.1
type=006, len=004: 10.50.5.12
type=012, len=031: "cumulus.rdu.cumulusnetworks.com" (string)
type=015, len=023: "rdu.cumulusnetworks.com" (string)
type=042, len=004: 10.50.5.11
type=051, len=004: 4000 (uint32)
type=053, len=001: 5 (uint8)
type=054, len=004: 10.50.5.11
type=058, len=004: 900 (uint32)
type=059, len=004: 1800 (uint32)
type=119, len=123: "rdu.cumulusnetworks.com." (fqdn) "mvlab.cumulusnetworks.com." (fqdn) "lab.cumulusnetworks.com." (fqdn) "syd.cumulusnetworks.com." (fqdn) "cumulusnetworks.com." (fqdn)
type=239, len=045: "http://monster-01.rdu.cumulusnetworks.com/ztp" (string)
2019-01-30 12:12:19.330 DEBUG [kea-dhcp4.packets/8334] DHCP4_BUFFER_RECEIVED received buffer from 10.50.11.11:68 to 10.50.5.11:67 over interface eth0
2019-01-30 12:12:19.330 DEBUG [kea-dhcp4.options/8334] DHCP4_BUFFER_UNPACK parsing buffer received from 10.50.11.11 to 10.50.5.11 over interface eth0
2019-01-30 12:12:19.330 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_OPTION Pushing option 93 with value 0x
2019-01-30 12:12:19.330 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_HEXSTRING Pushing hex string 0x0007
2019-01-30 12:12:19.330 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_EQUAL Popping 0x0007 and 0x pushing result 'false'
2019-01-30 12:12:19.330 DEBUG [kea-dhcp4.options/8334] EVAL_RESULT Expression ipxe_efi_bc evaluated to 0
2019-01-30 12:12:19.330 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_OPTION Pushing option 93 with value 0x
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_HEXSTRING Pushing hex string 0x0009
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_EQUAL Popping 0x0009 and 0x pushing result 'false'
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.options/8334] EVAL_RESULT Expression ipxe_efi_x86_64 evaluated to 0
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_OPTION Pushing option 93 with value 0x
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_HEXSTRING Pushing hex string 0x0006
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_EQUAL Popping 0x0006 and 0x pushing result 'false'
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.options/8334] EVAL_RESULT Expression pxe_efi_ia32 evaluated to 0
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_OPTION Pushing option 93 with value 0x
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_HEXSTRING Pushing hex string 0x0000
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.eval/8334] EVAL_DEBUG_EQUAL Popping 0x0000 and 0x pushing result 'false'
2019-01-30 12:12:19.331 DEBUG [kea-dhcp4.options/8334] EVAL_RESULT Expression pxe_x86 evaluated to 0
Not Working DHCPOFFER
=====================
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.packets/8334] DHCP4_PACKET_RECEIVED [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: DHCPDISCOVER (type 1) received from 10.50.1.22 to 10.50.5.11 on interface eth0
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.packets/8334] DHCP4_QUERY_DATA [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011, packet details: local_address=10.50.5.11:67, remote_address=10.50.1.22:67, msg_type=DHCPDISCOVER (1), transid=0x2b309011,
options:
type=012, len=035: "act-5812-51.rdu.cumulusnetworks.com" (string)
type=050, len=004: 10.50.22.110 (ipv4-address)
type=051, len=004: 7200 (uint32)
type=053, len=001: 1 (uint8)
type=055, len=014: 1(uint8) 28(uint8) 2(uint8) 3(uint8) 15(uint8) 6(uint8) 119(uint8) 12(uint8) 44(uint8) 47(uint8) 26(uint8) 121(uint8) 42(uint8) 239(uint8)
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.packets/8334] DHCP4_SUBNET_SELECTED [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: the subnet with ID 22 was selected for client assignments
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.packets/8334] DHCP4_SUBNET_DATA [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: the selected subnet details: 10.50.22.0/24
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 22, identified by hwaddr=A82BB53A1C28
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using identifier: hwaddr=A82BB53A1C28
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=A82BB53A1C28, found 0 host(s)
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.hosts/8334] HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 22 and identifier hwaddr=A82BB53A1C28
2019-01-30 12:12:26.504 DEBUG [kea-dhcp4.hosts/8334] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for subnet id 22, identified by hwaddr=A82BB53A1C28
2019-01-30 12:12:26.505 DEBUG [kea-dhcp4.hosts/8334] HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_IDENTIFIER_HOST using subnet id 22 and identifier hwaddr=A82BB53A1C28, found host: hwaddr=A82BB53A1C28 ipv4_subnet_id=22 ipv6_subnet_id=22 hostname=act-5812-51 ipv4_reservation=10.50.22.110 siaddr=(no) sname=(empty) file=(empty) ipv6_reservations=(none)
2019-01-30 12:12:26.505 DEBUG [kea-dhcp4.ddns/8334] DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: processing client's Hostname option
2019-01-30 12:12:26.505 DEBUG [kea-dhcp4.ddns/8334] DHCP4_CLIENT_HOSTNAME_DATA [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: client sent Hostname option: act-5812-51.rdu.cumulusnetworks.com
2019-01-30 12:12:26.505 DEBUG [kea-dhcp4.ddns/8334] DHCP4_RESERVED_HOSTNAME_ASSIGNED [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: server assigned reserved hostname act-5812-51.rdu.cumulusnetworks.com
2019-01-30 12:12:26.505 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_MYSQL_GET_HWADDR obtaining IPv4 leases for hardware address hwtype=1 a8:2b:b5:3a:1c:28
2019-01-30 12:12:26.506 DEBUG [kea-dhcp4.alloc-engine/8334] ALLOC_ENGINE_V4_DISCOVER_HR client [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011 sending DHCPDISCOVER has reservation for the address 10.50.22.110
2019-01-30 12:12:26.506 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_MYSQL_GET_ADDR4 obtaining IPv4 lease for address 10.50.22.110
2019-01-30 12:12:26.506 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_MYSQL_GET_ADDR4 obtaining IPv4 lease for address 10.50.22.110
2019-01-30 12:12:26.507 INFO [kea-dhcp4.leases/8334] DHCP4_LEASE_ADVERT [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: lease 10.50.22.110 will be advertised
2019-01-30 12:12:26.507 DEBUG [kea-dhcp4.dhcp4/8334] DHCP4_CLIENTID_IGNORED_FOR_LEASES [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: not using client identifier for lease allocation for subnet 22
2019-01-30 12:12:26.507 DEBUG [kea-dhcp4.options/8334] DHCP4_PACKET_PACK [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: preparing on-wire format of the packet to be sent
2019-01-30 12:12:26.507 ERROR [kea-dhcp4.options/8334] DHCP4_PACKET_PACK_FAIL [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: preparing on-wire-format of the packet to be sent failed DHCPv4 Option 239 is too big. At most 255 bytes are supported.
2019-01-30 12:12:26.507 DEBUG [kea-dhcp4.packets/8334] DHCP4_PACKET_SEND [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: trying to send packet DHCPOFFER (type 2) from 10.50.5.11:67 to 10.50.22.1:67 on interface eth0
2019-01-30 12:12:26.507 DEBUG [kea-dhcp4.packets/8334] DHCP4_RESPONSE_DATA [hwtype=1 a8:2b:b5:3a:1c:28], cid=[no info], tid=0x2b309011: responding with packet DHCPOFFER (type 2), packet details: local_address=10.50.5.11:67, remote_address=10.50.22.1:67, msg_type=DHCPOFFER (2), transid=0x2b309011,
options:
type=001, len=004: 4294967040 (uint32)
type=003, len=004: 10.50.22.1
type=006, len=004: 10.50.5.12
type=012, len=035: "act-5812-51.rdu.cumulusnetworks.com" (string)
type=015, len=023: "rdu.cumulusnetworks.com" (string)
type=042, len=004: 10.50.5.11
type=051, len=004: 4000 (uint32)
type=053, len=001: 2 (uint8)
type=054, len=004: 10.50.5.11
type=058, len=004: 900 (uint32)
type=059, len=004: 1800 (uint32)
type=119, len=123: "rdu.cumulusnetworks.com." (fqdn) "mvlab.cumulusnetworks.com." (fqdn) "lab.cumulusnetworks.com." (fqdn) "syd.cumulusnetworks.com." (fqdn) "cumulusnetworks.com." (fqdn)
type=239, len=4096: "" (string)
2019-01-30 12:12:26.508 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_TIMERMGR_RUN_TIMER_OPERATION running operation for timer: reclaim-expired-leases
2019-01-30 12:12:26.508 DEBUG [kea-dhcp4.alloc-engine/8334] ALLOC_ENGINE_V4_LEASES_RECLAMATION_START starting reclamation of expired leases (limit = 100 leases or 250 milliseconds)
2019-01-30 12:12:26.508 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_MYSQL_GET_EXPIRED4 obtaining maximum 101 of expired IPv4 leases
2019-01-30 12:12:26.509 DEBUG [kea-dhcp4.alloc-engine/8334] ALLOC_ENGINE_V4_LEASES_RECLAMATION_COMPLETE reclaimed 0 leases in 0.908 ms
2019-01-30 12:12:26.509 DEBUG [kea-dhcp4.alloc-engine/8334] ALLOC_ENGINE_V4_NO_MORE_EXPIRED_LEASES all expired leases have been reclaimed
2019-01-30 12:12:26.509 DEBUG [kea-dhcp4.dhcpsrv/8334] DHCPSRV_TIMERMGR_START_TIMER starting timer: reclaim-expired-leases
More information about the Kea-users
mailing list