Kea Users

[Kea-users] Kea 1.6.3: ALLOC_ENGINE_V6_ALLOC_FAIL warning message even if the address is successfully assigned

classic Classic list List threaded Threaded
♦
♦
 2 messages Options
laaubert
Reply | Threaded
Open this post in threaded view
♦
♦
|

[Kea-users] Kea 1.6.3: ALLOC_ENGINE_V6_ALLOC_FAIL warning message even if the address is successfully assigned

laaubert
This post was updated on .
Hi,

I'm using Kea 1.6.3 to assign IPv6 addresses to endpoints which support rapid-commit only. The addresses are assigned but I do see the following warning messages in the logs:

2020-11-24 21:26:58.831 INFO  [kea-dhcp6.leases/1] DHCP6_LEASE_ALLOC duid=[00:03:00:06:00:17:3b:10:00:44:00:21], tid=0xa852e0: lease for address fd10:5::1 and iaid=0 has been allocated for 2592000 seconds
2020-11-24 21:26:58.832 WARN  [kea-dhcp6.alloc-engine/1] ALLOC_ENGINE_V6_ALLOC_FAIL duid=[00:03:00:06:00:17:3b:10:00:44:00:21], tid=0xa852e0: failed to allocate an IPv6 address after 0 attempt(s)
2020-11-24 21:26:59.919 INFO  [kea-dhcp6.leases/1] DHCP6_LEASE_ALLOC duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xb20788: lease for address fd10:5::2 and iaid=0 has been allocated for 2592000 seconds
2020-11-24 21:26:59.919 WARN  [kea-dhcp6.alloc-engine/1] ALLOC_ENGINE_V6_ALLOC_FAIL duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xb20788: failed to allocate an IPv6 address after 0 attempt(s)

We can see the assigned addresses being added to the leases file:

[admin@fanhe-ucse-1 ~]$ more /home/fanhe/dhcp-app/data/kea-leases6.csv
address,duid,valid_lifetime,expire,subnet_id,pref_lifetime,lease_type,iaid,prefix_len,fqdn_fwd,fqdn_rev,hostname,hwaddr,state,user_context
fd10:0:0:5::2,00:02:00:00:00:09:01:12:49:52:38:32:39:47:57:2d:4c:54:45:2d:4e:41:2d:41:4b:39:02:0b:46:54:58:32:30:33:39:5a:30:30:47,4294967295,5901218774,100,4294967295,0,0,128,0,0,,,0,
fd10:0:0:5::1,00:02:00:00:00:09:01:0a:43:47:52:31:32:34:30:2f:4b:39:02:0b:4a:41:44:32:30:30:31:30:30:50:57,4294967295,5901218818,100,4294967295,0,0,128,0,0,,,0,
fd10:5::1,00:03:00:06:00:17:3b:10:00:44:00:21,2592000,1608845218,201,2592000,0,0,128,0,0,,00:17:3b:10:00:44:00:21,0,
fd10:5::2,00:03:00:06:00:17:3b:05:00:5f:00:30,2592000,1608845219,201,2592000,0,0,128,0,0,,00:17:3b:05:00:5f:00:30,0,

My subnet6 config is the following:

{
        "calculate-tee-times": true,
        "id": 201,
        "option-data": [ ],
        "pd-pools": [ ],
        "pools": [
          {
            "option-data": [ ],
            "pool": "fd10:5::1-fd10:5::ffff:ffff:ffff:fffe"
          }
        ],
        "preferred-lifetime": 2592000,
        "rapid-commit": true,
        "relay": {
          "ip-addresses": [ ]
        },
        "reservation-mode": "all",
        "reservations": [ ],
        "subnet": "fd10:5::/64",
        "t1-percent": 0.5,
        "t2-percent": 0.8,
        "valid-lifetime": 2592000
      },


Should I be worried about those warnings or I can safely ignored them ?

Thanks for your support
laaubert
Reply | Threaded
Open this post in threaded view
♦
♦
|

Re: [Kea-users] Kea 1.6.3: ALLOC_ENGINE_V6_ALLOC_FAIL warning message even if the address is successfully assigned

laaubert
Below is the same sequence with logs set to DEBUG:

2021-01-22 13:06:16.011 DEBUG [kea-dhcp6.dhcpsrv/1]
DHCPSRV_TIMERMGR_RUN_TIMER_OPERATION running operation for timer:
reclaim-expired-leases
2021-01-22 13:06:16.011 DEBUG [kea-dhcp6.alloc-engine/1]
ALLOC_ENGINE_V6_LEASES_RECLAMATION_START starting reclamation of expired
leases (limit = 100 leases or 250 milliseconds)
2021-01-22 13:06:16.011 DEBUG [kea-dhcp6.dhcpsrv/1]
DHCPSRV_MEMFILE_GET_EXPIRED6 obtaining maximum 101 of expired IPv6 leases
2021-01-22 13:06:16.011 DEBUG [kea-dhcp6.alloc-engine/1]
ALLOC_ENGINE_V6_LEASES_RECLAMATION_COMPLETE reclaimed 0 leases in 0.020 ms
2021-01-22 13:06:16.011 DEBUG [kea-dhcp6.alloc-engine/1]
ALLOC_ENGINE_V6_NO_MORE_EXPIRED_LEASES all expired leases have been
reclaimed
2021-01-22 13:06:16.011 DEBUG [kea-dhcp6.dhcpsrv/1]
DHCPSRV_TIMERMGR_START_TIMER starting timer: reclaim-expired-leases
2021-01-22 13:06:19.081 DEBUG [kea-dhcp6.packets/1] DHCP6_BUFFER_RECEIVED
received buffer from fd10:2::2:547 to fd10::7f17:0 over interface eth0
2021-01-22 13:06:19.081 DEBUG [kea-dhcp6.options/1] DHCP6_BUFFER_UNPACK
parsing buffer received from fd10:2::2 to fd10::7f17 over interface eth0
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.packets/1] DHCP6_PACKET_RECEIVED
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: SOLICIT (type 1)
received from fd10:2::2 to fd10::7f17 on interface eth0
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.packets/1] DHCP6_QUERY_DATA
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc, packet details:
localAddr=[fd10::7f17]:0 remoteAddr=[fd10:2::2]:547
msgtype=1(SOLICIT), transid=0xafcafc
type=00001, len=00012: 00:03:00:06:00:17:3b:05:00:5f:00:30
type=00003(IA_NA), len=00012: iaid=0, t1=0, t2=0
type=00006, len=00002: 17(uint16)
type=00008, len=00002: 0 (uint16)
type=00014, len=00000:
type=00025(IA_PD), len=00012: iaid=0, t1=0, t2=0
1 relay(s):
relay[0]: msg-type=12(RELAY_FORWARD), hop-count=0,
link-address=fd10:1::, peer-address=fe80::217:3b05:5f:30, 2 option(s)
type=00018, len=00004: 00:00:00:17
type=00037, len=00022: 9 (uint32) 020041000000000A0003000100FEC897B048
(binary)

2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.dhcpsrv/1] DHCPSRV_CFGMGR_SUBNET6
retrieved subnet fd10:1::/64 for address hint fd10:1::
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.packets/1] DHCP6_SUBNET_SELECTED
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: the subnet with ID
1002 was selected for client assignments
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.packets/1] DHCP6_SUBNET_DATA
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: the selected
subnet details: fd10:1::/64
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv6 reservation
for subnet id 1002, identified by hwaddr=00173B05005F0030
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using
identifier: hwaddr=00173B05005F0030
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=00173B05005F0030,
found 0 host(s)
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id
1002 and identifier hwaddr=00173B05005F0030
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER get one host with IPv6 reservation
for subnet id 1002, identified by duid=0003000600173B05005F0030
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using
identifier: duid=0003000600173B05005F0030
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier
duid=0003000600173B05005F0030, found 0 host(s)
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ONE_SUBNET_ID_IDENTIFIER_NULL host not found using subnet id
1002 and identifier duid=0003000600173B05005F0030
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.dhcp6/1] DHCP6_CLASS_ASSIGNED
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: client packet has
been assigned to the following class(es): UNKNOWN
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.options/1] DHCP6_RAPID_COMMIT
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: Rapid Commit
option received, following 2-way exchange
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.leases/1]
DHCP6_PROCESS_IA_NA_REQUEST duid=[00:03:00:06:00:17:3b:05:00:5f:00:30],
tid=0xafcafc: server is processing IA_NA option with iaid=0 and hint=(no
hint)
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.dhcpsrv/1]
DHCPSRV_MEMFILE_GET_IAID_DUID obtaining IPv6 leases for IAID 0 and DUID
00:03:00:06:00:17:3b:05:00:5f:00:30 and lease type IA_NA
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.alloc-engine/1]
ALLOC_ENGINE_V6_ALLOC_LEASES_NO_HR no reservations found but leases exist
for client duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS6 get one host with reservation for
subnet id 1002 and including IPv6 address fd10:1::1
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ALL_SUBNET_ID_ADDRESS6 get all hosts with reservations for
subnet id 1002 and IPv6 address fd10:1::1
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ALL_SUBNET_ID_ADDRESS6_COUNT using subnet id 1002 and address
fd10:1::1, found 0 host(s)
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.hosts/1]
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS6_NULL host not found using subnet id
1002 and address fd10:1::1
2021-01-22 13:06:19.082 DEBUG [kea-dhcp6.dhcpsrv/1]
DHCPSRV_MEMFILE_UPDATE_ADDR6 updating IPv6 lease for address fd10:1::1
2021-01-22 13:06:19.083 INFO  [kea-dhcp6.leases/1] DHCP6_LEASE_ALLOC
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: lease for address
fd10:1::1 and iaid=0 has been allocated for 2592000 seconds
2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.leases/1] DHCP6_LEASE_DATA
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: detailed lease
information for iaid=0: Type:          IA_NA(0)
Address:       fd10:1::1
Prefix length: 128
IAID:          0
Pref life:     2592000
Valid life:    2592000
Cltt:          1611320779
DUID:          00:03:00:06:00:17:3b:05:00:5f:00:30
Hardware addr: 00:17:3b:05:00:5f:00:30
Subnet ID:     1002
State:         default

2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.leases/1]
DHCP6_PROCESS_IA_PD_REQUEST duid=[00:03:00:06:00:17:3b:05:00:5f:00:30],
tid=0xafcafc: server is processing IA_PD option with iaid=0 and hint=(no
hint)
2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.dhcpsrv/1]
DHCPSRV_MEMFILE_GET_IAID_DUID obtaining IPv6 leases for IAID 0 and DUID
00:03:00:06:00:17:3b:05:00:5f:00:30 and lease type IA_PD
2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.alloc-engine/1]
ALLOC_ENGINE_V6_ALLOC_UNRESERVED no static reservations available - trying
to dynamically allocate leases for client
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc
2021-01-22 13:06:19.083 WARN  [kea-dhcp6.alloc-engine/1]
ALLOC_ENGINE_V6_ALLOC_FAIL duid=[00:03:00:06:00:17:3b:05:00:5f:00:30],
tid=0xafcafc: failed to allocate an IPv6 address after 0 attempt(s)
2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.leases/1] DHCP6_PD_LEASE_ALLOC_FAIL
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: failed to grant a
prefix lease for iaid=0
2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.options/1]
DHCP6_ADD_STATUS_CODE_FOR_IA duid=[00:03:00:06:00:17:3b:05:00:5f:00:30],
tid=0xafcafc: adding Status Code to IA with iaid=0: NoPrefixAvail(6) "Sorry,
no prefixes could be allocated."
2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.packets/1] DHCP6_PACKET_SEND
duid=[00:03:00:06:00:17:3b:05:00:5f:00:30], tid=0xafcafc: trying to send
packet REPLY (type 7) from [fd10::7f17]:547 to [fd10:2::2]:547 on interface
eth0
2021-01-22 13:06:19.083 DEBUG [kea-dhcp6.packets/1] DHCP6_RESPONSE_DATA
responding with packet type 7 data is localAddr=[fd10::7f17]:547
remoteAddr=[fd10:2::2]:547
msgtype=7(REPLY), transid=0xafcafc
type=00001, len=00012: 00:03:00:06:00:17:3b:05:00:5f:00:30
type=00002, len=00012: 00:02:00:00:09:bf:e2:00:df:5d:b6:e2
type=00003(IA_NA), len=00040: iaid=0, t1=1296000, t2=2073600,
options:
  type=00005(IAADDR), len=00024: address=fd10:1::1, preferred-lft=2592000,
valid-lft=2592000
type=00014, len=00000:
type=00017, len=00024: 26484 (uint32),
options:
  type=00001, len=00016: fd10::1:d (ipv6-address)
type=00025(IA_PD), len=00056: iaid=0, t1=0, t2=0,
options:
  type=00013, len=00040: NoPrefixAvail(6) "Sorry, no prefixes could be
allocated."
1 relay(s):
relay[0]: msg-type=13(RELAY_REPLY), hop-count=0,
link-address=fd10:1::, peer-address=fe80::217:3b05:5f:30, 1 option(s)
type=00018, len=00004: 00:00:00:17





--
Sent from: http://kea-users.7364.n8.nabble.com/
_______________________________________________
ISC funds the development of this software with paid support subscriptions. Contact us at https://www.isc.org/contact/ for more information.

To unsubscribe visit https://lists.isc.org/mailman/listinfo/kea-users.

Kea-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/kea-users
Free forum by Nabble Edit this page