Send kea-dev mailing list submissions to
[email protected]
To subscribe or unsubscribe via the World Wide Web, visit
https://lists.isc.org/mailman/listinfo/kea-dev
or, via email, send a message with subject or body 'help' to
[email protected]
You can reach the person managing the list at
[email protected]
When replying, please edit your Subject line so it is more specific
than "Re: Contents of kea-dev digest..."
Today's Topics:
1. KEA ignoring subnet choice between hooks (Hrei?ar J?elsson)
----------------------------------------------------------------------
Message: 1
Date: Tue, 6 Nov 2018 13:50:50 +0000
From: Hrei?ar J?elsson <[email protected]>
To: "'[email protected]'" <[email protected]>
Subject: [kea-dev] KEA ignoring subnet choice between hooks
Message-ID: <[email protected]>
Content-Type: text/plain; charset="iso-8859-1"
Hi, I'm developing a hook that govern which subnet is selected from multiple
subnets in a shared network for an incoming DHCP package. My network has
several subnets per each service (VLAN), one which has restricted addresses
(10.20x.x.x) and several that have non-restricted addresses (192.168.x.x in my
dev env). The hook I have now does this by using lease policies which it reads
from external Redis database. The problem I'm encountering is moving devices
between subnets after they have once got a lease. When a device has got a lease
from one subnet it is hard to get KEA to provision a lease from another one as
it is overwriting the subnet of choice made in subnet4_select hook in the
lease4_select hook. This is done in the main process in between these two hooks
as I put my choice in subnet4_select by:
int subnet4_select(CalloutHandle& handle) {
Subnet4Ptr subnet;
handle.getArgument("subnet4", subnet);
...
// set chosen subnet to Subnet4Ptr my_subnet_choice
...
handle.setArgument("subnet4", my_subnet_choice);
handle.setContext("subnet4", my_subnet_choice);
}
But when I check the subnet in lease4_select KEA has change it to the one
previously used:
int lease4_select(CalloutHandle& handle) {
handle.getArgument("subnet4", kea_subnet);
handle.getContext("subnet4", my_subnet_choice);
if(kea_subnet->getID() != my_subnet_choice->getID())
{
LOG_DEBUG(my_logger,50, LEASE4_SELECT_MISMATCH);
handle.setContext(CONTEXT_PARAMETER_NAK, true);
lease->decline(0);
}
I added this check & nak code in lease4_select and lease4_renew hooks to deal
with the cases when a device is sending a renew message to force the client to
send a discover message insted, but this ends in discover nak loop between KEA
and that client. I can resolve this behavior be reloading KEA or by removing
that client record from the mem file.
Lease affinity is one thing I imagine could be in my way, but I believe I have
turned it off with the following config and still seeing this behavior:
"expired-leases-processing": {
"flush-reclaimed-timer-wait-time": 0,
"hold-reclaimed-time": 0,
"max-reclaim-leases": 0,
"max-reclaim-time": 0,
"reclaim-timer-wait-time": 30,
"unwarned-reclaim-cycles": 5
}
Any other ideas on what could explain this behavior? I see a
DHCP4_SUBNET_DYNAMICALLY_CHANGED message in the provided logs that I would like
to know more about.
Here are some more logs to support my case:
### kea dhcp log
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUTS_BEGIN
begin all callouts for hook subnet4_select
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUT_CALLED
hooks library with index 1 has called a callout on hook subnet4_select that has
address 0x7f491302ab5f (callout duration: 0.172 ms)
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUTS_COMPLETE
completed callouts for hook subnet4_select (total callouts duration: 0.172 ms)
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.packets/7456] DHCP4_SUBNET_SELECTED
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463: the
subnet with ID 6 was selected for client assignments
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.packets/7456] DHCP4_SUBNET_DATA
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463: the
selected subnet details: 192.168.30.0/24
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for
subnet id 6, identified by hwaddr=C8D3FFEEFF4C
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using identifier:
hwaddr=C8D3FFEEFF4C
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=C8D3FFEEFF4C, found
0 host(s)
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 6
and identifier hwaddr=C8D3FFEEFF4C
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv4 reservation for
subnet id 6, identified by client-id=01C8D3FFEEFF4C
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using identifier:
client-id=01C8D3FFEEFF4C
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier client-id=01C8D3FFEEFF4C,
found 0 host(s)
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.hosts/7456]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id 6
and identifier client-id=01C8D3FFEEFF4C
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.dhcp4/7456] DHCP4_CLASS_ASSIGNED
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463:
client packet has been assigned to the following class(es): UNKNOWN
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.dhcp4/7456] DHCP4_CLASS_ASSIGNED
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463:
client packet has been assigned to the following class(es): ALL,
VENDOR_CLASS_MSFT 5.0, UNKNOWN
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.ddns/7456]
DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 c8:d3:ff:ee:ff:4c],
cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463: processing client's Hostname option
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.ddns/7456] DHCP4_CLIENT_HOSTNAME_DATA
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463:
client sent Hostname option: DESKTOP-FKUL6EB
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.ddns/7456] DHCP4_CLIENT_HOSTNAME_DATA
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463:
client sent Hostname option: DESKTOP-FKUL6EB
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.ddns/7456]
DHCP4_RESPONSE_HOSTNAME_DATA [hwtype=1 c8:d3:ff:ee:ff:4c],
cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463: including Hostname option in the
server's response: DESKTOP-FKUL6EB
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.dhcpsrv/7456]
DHCPSRV_MEMFILE_GET_CLIENTID obtaining IPv4 leases for client ID
01:c8:d3:ff:ee:ff:4c
2018-10-30 12:30:19.466 DEBUG [kea-dhcp4.dhcpsrv/7456]
DHCPSRV_MEMFILE_GET_HWADDR obtaining IPv4 leases for hardware address hwtype=1
c8:d3:ff:ee:ff:4c
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.alloc-engine/7456]
ALLOC_ENGINE_V4_OFFER_NEW_LEASE allocation engine will try to offer new lease
to the client [hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c],
tid=0xabef9463
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.dhcpsrv/7456]
DHCPSRV_MEMFILE_GET_ADDR4 obtaining IPv4 lease for address 10.206.0.13
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUTS_BEGIN
begin all callouts for hook lease4_select
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUT_CALLED
hooks library with index 1 has called a callout on hook lease4_select that has
address 0x7f491302b6ca (callout duration: 0.146 ms)
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUTS_COMPLETE
completed callouts for hook lease4_select (total callouts duration: 0.146 ms)
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.dhcpsrv/7456]
DHCPSRV_MEMFILE_GET_ADDR4 obtaining IPv4 lease for address 10.206.0.13
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.packets/7456]
DHCP4_SUBNET_DYNAMICALLY_CHANGED [hwtype=1 c8:d3:ff:ee:ff:4c],
cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463: changed selected subnet
192.168.30.0/24 to subnet 10.206.0.0/22 from shared network GR-Internet-AG06
for client assignments
2018-10-30 12:30:19.467 INFO [kea-dhcp4.leases/7456] DHCP4_LEASE_ADVERT
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463: lease
10.206.0.13 will be advertised
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.ddns/7456]
DHCP4_RESPONSE_HOSTNAME_GENERATE [hwtype=1 c8:d3:ff:ee:ff:4c],
cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463: server has generated hostname
myhost-10-206-0-13 for the client
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUTS_BEGIN
begin all callouts for hook pkt4_send
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUT_CALLED
hooks library with index 1 has called a callout on hook pkt4_send that has
address 0x7f491302a4db (callout duration: 0.093 ms)
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.callouts/7456] HOOKS_CALLOUTS_COMPLETE
completed callouts for hook pkt4_send (total callouts duration: 0.093 ms)
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.options/7456] DHCP4_PACKET_PACK
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463:
preparing on-wire format of the packet to be sent
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.packets/7456] DHCP4_PACKET_SEND
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463:
trying to send packet DHCPNAK (type 6) from 192.168.15.80:67 to 10.206.0.2:67
on interface ens33
2018-10-30 12:30:19.467 DEBUG [kea-dhcp4.packets/7456] DHCP4_RESPONSE_DATA
[hwtype=1 c8:d3:ff:ee:ff:4c], cid=[01:c8:d3:ff:ee:ff:4c], tid=0xabef9463:
responding with packet DHCPNAK (type 6), packet details:
local_address=192.168.15.80:67, remote_address=10.206.0.2:67, msg_type=DHCPNAK
(6), transid=0xabef9463,
### my hook log
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456] start
subnet4_select
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456]
SUBNET4_SELECT_PROCESSING started processing subnet in shared-network
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456]
SUBNET4_SELECT_CAPACITY subnet: "10.206.0.0/22" , capacity: 1019
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456]
SUBNET4_SELECT_CAPACITY subnet: "192.168.30.0/24" , capacity: 245
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456]
SUBNET4_SELECT_ALLOWED using allowed subnet: 192.168.30.0/24
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456] Start
lease4_select
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456]
LEASE4_SELECT_VIRKIR_SUBNET virkir selects this subnet: 192.168.30.0/24
2018-10-30 12:30:19.463 DEBUG [kea-dhcp4.virkir-kea-hook/7456]
LEASE4_SELECT_KEA_SUBNET kea want to select this subnet: 10.206.0.0/22
2018-10-30 12:30:19.464 DEBUG [kea-dhcp4.virkir-kea-hook/7456]
LEASE4_SELECT_MISMATCH there is a mismatch in subnet selection, clean database
and respond with nak
2018-10-30 12:30:19.464 DEBUG [kea-dhcp4.virkir-kea-hook/7456] pkt4_send Start
2018-10-30 12:30:19.464 DEBUG [kea-dhcp4.virkir-kea-hook/7456] PKT4_SEND_NAK
sending nak package to client: c8:d3:ff:ee:ff:4c
Regards, Hrei?ar.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://lists.isc.org/pipermail/kea-dev/attachments/20181106/b619be0d/attachment.html>
------------------------------
Subject: Digest Footer
_______________________________________________
kea-dev mailing list
[email protected]
https://lists.isc.org/mailman/listinfo/kea-dev
------------------------------
End of kea-dev Digest, Vol 56, Issue 1
**************************************
