[Kea-users] HA Load Balancing not working

sven.roehrig at web.de sven.roehrig at web.de
Tue Oct 9 06:41:07 UTC 2018


Hello,

thank you for responding. I tried to play with the timers with no success.
Any ideas?

Package: kea-dhcp4-server
Version: 1.4.0.P1-2

"high-availability": [ {
 
"this-server-name": "server1",
                                                                "mode":
"load-balancing",
 
"heartbeat-delay": 1000,
 
"max-ack-delay": 1000,
 
"max-response-delay": 1000,
 
"max-unacked-messages": 0,
                                                                "peers": [
 
{
 
"name": "server1",
 
"url": "http://192.168.62.5:8080/",
 
"role": "primary",
 
"auto-failover": true
 
},
 
{
 
"name": "server2",
 
"url": "http://192.168.62.6:8080/",
 
"role": "secondary",
 
"auto-failover": true
 
}
                                                                ]


2018-10-09 08:12:02.974 DEBUG [kea-dhcp4.http/2474] HTTP_CLIENT_REQUEST_SEND
sending HTTP request POST / HTTP/1.1 to http://192.168.62.5:8080/
2018-10-09 08:12:02.974 DEBUG [kea-dhcp4.http/2474]
HTTP_CLIENT_REQUEST_SEND_DETAILS detailed information about request sent to
http://192.168.62.5:8080/:
POST / HTTP/1.1
Content-Length: 53
Content-Type: application/json

{ "command": "ha-heartbeat", "service": [ "dhcp4" ] }
2018-10-09 08:12:03.976 DEBUG [kea-dhcp4.http/2474]
HTTP_SERVER_RESPONSE_RECEIVED received HTTP response from
http://192.168.62.5:8080/
2018-10-09 08:12:03.976 DEBUG [kea-dhcp4.http/2474]
HTTP_SERVER_RESPONSE_RECEIVED_DETAILS detailed information about well formed
response received from http://192.168.62.5:8080/:
HTTP/1.1 200 OK
Content-Length: 140
Content-Type: application/json
Date: Tue, 09 Oct 2018 06:12:02 GMT

[ { "result": 1, "text": "unable to forward command to the dhcp4 service: No
such file or directory. The server is likely to be offline" } ]
2018-10-09 08:12:03.976 WARN  [kea-dhcp4.ha-hooks/2474] HA_HEARTBEAT_FAILED
heartbeat to server1 (http://192.168.62.5:8080/) failed: unable to forward
command to the dhcp4 service: No such file or directory. The server is
likely to be offline, error code 1
2018-10-09 08:12:04.727 DEBUG [kea-dhcp4.packets/2474] DHCP4_BUFFER_RECEIVED
received buffer from 212.122.55.17:67 to 185.78.252.54:67 over interface
ens18
2018-10-09 08:12:04.727 DEBUG [kea-dhcp4.callouts/2474] HOOKS_CALLOUTS_BEGIN
begin all callouts for hook buffer4_receive
2018-10-09 08:12:04.727 DEBUG [kea-dhcp4.callouts/2474] HOOKS_CALLOUT_CALLED
hooks library with index 2 has called a callout on hook buffer4_receive that
has address 0x7f6dbbd1c920 (callout duration: 0.138 ms)
2018-10-09 08:12:04.727 DEBUG [kea-dhcp4.callouts/2474]
HOOKS_CALLOUTS_COMPLETE completed callouts for hook buffer4_receive (total
callouts duration: 0.138 ms)
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.hooks/2474]
DHCP4_HOOK_BUFFER_RCVD_SKIP received buffer from 212.122.55.17 to
185.78.252.54 over interface ens18 is not parsed because a callout set the
next step to SKIP.
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '4'
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 4, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'pktc'
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x706B7463 and 0x pushing result 'false'
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.728 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '6'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 6, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'docsis'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x646F63736973 and 0x pushing result 'false'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OR Popping
'false' and 'false' pushing 'false'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_NOT Popping
'false' pushing 'true'
2018-10-09 08:12:04.729 INFO  [kea-dhcp4.options/2474] EVAL_RESULT
Expression CLASS-CPE evaluated to 1
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '6'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 6, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'docsis'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x646F63736973 and 0x pushing result 'false'
2018-10-09 08:12:04.729 DEBUG [kea-dhcp4.options/2474] EVAL_RESULT
Expression CLASS-CM evaluated to 0
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '4'
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 4, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'pktc'
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x706B7463 and 0x pushing result 'false'
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.options/2474] EVAL_RESULT
Expression CLASS-MTA evaluated to 0
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.packets/2474] DHCP4_PACKET_RECEIVED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: DHCPDISCOVER
(type 1) received from 212.122.55.17 to 185.78.252.54 on interface ens18
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.packets/2474] DHCP4_QUERY_DATA
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9, packet details:
local_address=185.78.252.54:67, remote_address=212.122.55.17:67,
msg_type=DHCPDISCOVER (1), transid=0x1701b4b9,
options:
  type=053, len=001: 1 (uint8)
  type=055, len=005: 1(uint8) 28(uint8) 3(uint8) 15(uint8) 6(uint8)
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.packets/2474] DHCP4_SUBNET_SELECTED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: the subnet with
ID 1 was selected for client assignments
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.packets/2474] DHCP4_SUBNET_DATA
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: the selected
subnet details: 192.168.225.0/24
2018-10-09 08:12:04.730 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using
identifier: hwaddr=000000111111
2018-10-09 08:12:04.731 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=000000111111,
found 0 host(s)
2018-10-09 08:12:04.731 DEBUG [kea-dhcp4.dhcp4/2474] DHCP4_CLASS_ASSIGNED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: client packet
has been assigned to the following class(es): UNKNOWN
2018-10-09 08:12:04.731 DEBUG [kea-dhcp4.dhcp4/2474] DHCP4_CLASS_ASSIGNED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: client packet
has been assigned to the following class(es): HA_server2, ALL, CLASS-CPE,
UNKNOWN
2018-10-09 08:12:04.731 DEBUG [kea-dhcp4.ddns/2474]
DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 00:00:00:11:11:11], cid=[no info],
tid=0x1701b4b9: processing client's Hostname option
2018-10-09 08:12:04.731 DEBUG [kea-dhcp4.dhcpsrv/2474]
DHCPSRV_MYSQL_GET_HWADDR obtaining IPv4 leases for hardware address hwtype=1
00:00:00:11:11:11
2018-10-09 08:12:04.732 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for
subnet id 1 and IPv4 address 192.168.225.10
2018-10-09 08:12:04.732 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_ADDRESS4 get all hosts with reservations for IPv4 address
192.168.225.10
2018-10-09 08:12:04.732 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 192.168.225.10, found 0
host(s)
2018-10-09 08:12:04.732 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 1
and address 192.168.225.10
2018-10-09 08:12:04.732 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate sources for
host using subnet id 1 and address 192.168.225.10
2018-10-09 08:12:04.732 DEBUG [kea-dhcp4.alloc-engine/2474]
ALLOC_ENGINE_V4_OFFER_EXISTING_LEASE allocation engine will try to offer
existing lease to the client [hwtype=1 00:00:00:11:11:11], cid=[no info],
tid=0x1701b4b9
2018-10-09 08:12:04.732 INFO  [kea-dhcp4.leases/2474] DHCP4_LEASE_ADVERT
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: lease
192.168.225.10 will be advertised
2018-10-09 08:12:04.732 DEBUG [kea-dhcp4.dhcp4/2474]
DHCP4_CLIENTID_IGNORED_FOR_LEASES [hwtype=1 00:00:00:11:11:11], cid=[no
info], tid=0x1701b4b9: not using client identifier for lease allocation for
subnet 1
2018-10-09 08:12:04.733 DEBUG [kea-dhcp4.options/2474] DHCP4_PACKET_PACK
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: preparing
on-wire format of the packet to be sent
2018-10-09 08:12:04.733 DEBUG [kea-dhcp4.packets/2474] DHCP4_PACKET_SEND
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: trying to send
packet DHCPOFFER (type 2) from 185.78.252.54:67 to 192.168.62.24:67 on
interface ens18
2018-10-09 08:12:04.733 DEBUG [kea-dhcp4.packets/2474] DHCP4_RESPONSE_DATA
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: responding with
packet DHCPOFFER (type 2), packet details: local_address=185.78.252.54:67,
remote_address=192.168.62.24:67, msg_type=DHCPOFFER (2), transid=0x1701b4b9,
options:
  type=001, len=004: 4294967040 (uint32)  
2018-10-09 08:12:04.734 DEBUG [kea-dhcp4.packets/2474] DHCP4_BUFFER_RECEIVED
received buffer from 212.122.55.17:67 to 185.78.252.54:67 over interface
ens18
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.callouts/2474] HOOKS_CALLOUTS_BEGIN
begin all callouts for hook buffer4_receive
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.callouts/2474] HOOKS_CALLOUT_CALLED
hooks library with index 2 has called a callout on hook buffer4_receive that
has address 0x7f6dbbd1c920 (callout duration: 0.134 ms)
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.callouts/2474]
HOOKS_CALLOUTS_COMPLETE completed callouts for hook buffer4_receive (total
callouts duration: 0.134 ms)
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.hooks/2474]
DHCP4_HOOK_BUFFER_RCVD_SKIP received buffer from 212.122.55.17 to
185.78.252.54 over interface ens18 is not parsed because a callout set the
next step to SKIP.
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '4'
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 4, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'pktc'
2018-10-09 08:12:04.735 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x706B7463 and 0x pushing result 'false'
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '6'
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 6, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'docsis'
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x646F63736973 and 0x pushing result 'false'
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OR Popping
'false' and 'false' pushing 'false'
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_NOT Popping
'false' pushing 'true'
2018-10-09 08:12:04.736 INFO  [kea-dhcp4.options/2474] EVAL_RESULT
Expression CLASS-CPE evaluated to 1
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.736 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '6'
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 6, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'docsis'
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x646F63736973 and 0x pushing result 'false'
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.options/2474] EVAL_RESULT
Expression CLASS-CM evaluated to 0
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_OPTION
Pushing option 60 with value 0x
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '0'
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string '4'
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474]
EVAL_DEBUG_SUBSTRING_EMPTY Popping length 4, start 0, string 0x pushing
result 0x
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_STRING
Pushing text string 'pktc'
2018-10-09 08:12:04.737 DEBUG [kea-dhcp4.eval/2474] EVAL_DEBUG_EQUAL Popping
0x706B7463 and 0x pushing result 'false'
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.options/2474] EVAL_RESULT
Expression CLASS-MTA evaluated to 0
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.packets/2474] DHCP4_PACKET_RECEIVED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: DHCPREQUEST
(type 3) received from 212.122.55.17 to 185.78.252.54 on interface ens18
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.packets/2474] DHCP4_QUERY_DATA
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9, packet details:
local_address=185.78.252.54:67, remote_address=212.122.55.17:67,
msg_type=DHCPREQUEST (3), transid=0x1701b4b9,
options:
  type=050, len=004: 192.168.225.10 (ipv4-address)
  type=053, len=001: 3 (uint8)
  type=054, len=004: 185.78.252.54 (ipv4-address)
  type=055, len=005: 1(uint8) 28(uint8) 3(uint8) 15(uint8) 6(uint8)
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.packets/2474] DHCP4_SUBNET_SELECTED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: the subnet with
ID 1 was selected for client assignments
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.packets/2474] DHCP4_SUBNET_DATA
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: the selected
subnet details: 192.168.225.0/24
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using
identifier: hwaddr=000000111111
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier hwaddr=000000111111,
found 0 host(s)
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.dhcp4/2474] DHCP4_CLASS_ASSIGNED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: client packet
has been assigned to the following class(es): UNKNOWN
2018-10-09 08:12:04.738 DEBUG [kea-dhcp4.dhcp4/2474] DHCP4_CLASS_ASSIGNED
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: client packet
has been assigned to the following class(es): HA_server2, ALL, CLASS-CPE,
UNKNOWN
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.ddns/2474]
DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 00:00:00:11:11:11], cid=[no info],
tid=0x1701b4b9: processing client's Hostname option
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.dhcpsrv/2474]
DHCPSRV_MYSQL_GET_HWADDR obtaining IPv4 leases for hardware address hwtype=1
00:00:00:11:11:11
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for
subnet id 1 and IPv4 address 192.168.225.10
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_ADDRESS4 get all hosts with reservations for IPv4 address
192.168.225.10
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 192.168.225.10, found 0
host(s)
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet id 1
and address 192.168.225.10
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.hosts/2474]
HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate sources for
host using subnet id 1 and address 192.168.225.10
2018-10-09 08:12:04.739 DEBUG [kea-dhcp4.dhcpsrv/2474]
DHCPSRV_MYSQL_GET_ADDR4 obtaining IPv4 lease for address 192.168.225.10
2018-10-09 08:12:04.740 DEBUG [kea-dhcp4.alloc-engine/2474]
ALLOC_ENGINE_V4_REQUEST_EXTEND_LEASE [hwtype=1 00:00:00:11:11:11], cid=[no
info], tid=0x1701b4b9: extending lifetime of the lease for address
192.168.225.10
2018-10-09 08:12:04.740 DEBUG [kea-dhcp4.dhcpsrv/2474]
DHCPSRV_MYSQL_UPDATE_ADDR4 updating IPv4 lease for address 192.168.225.10
2018-10-09 08:12:04.742 INFO  [kea-dhcp4.leases/2474] DHCP4_LEASE_ALLOC
[hwtype=1 00:00:00:11:11:11], cid=[no info], tid=0x1701b4b9: lease
192.168.225.10 has been allocated
2018-10-09 08:12:04.742 DEBUG [kea-dhcp4.dhcp4/2474]
DHCP4_CLIENTID_IGNORED_FOR_LEASES [hwtype=1 00:00:00:11:11:11], cid=[no
info], tid=0x1701b4b9: not using client identifier for lease allocation for
subnet 1
2018-10-09 08:12:04.742 DEBUG [kea-dhcp4.callouts/2474] HOOKS_CALLOUTS_BEGIN
begin all callouts for hook leases4_committed
2018-10-09 08:12:04.742 DEBUG [kea-dhcp4.http/2474] HTTP_CLIENT_REQUEST_SEND
sending HTTP request POST / HTTP/1.1 to http://192.168.62.5:8080/
2018-10-09 08:12:04.742 DEBUG [kea-dhcp4.http/2474]
HTTP_CLIENT_REQUEST_SEND_DETAILS detailed information about request sent to
http://192.168.62.5:8080/:
POST / HTTP/1.1
Content-Length: 283
Content-Type: application/json

{ "arguments": { "expire": 1539069524, "force-create": true, "fqdn-fwd":
false, "fqdn-rev": false, "hostname": "", "hw-address": "00:00:00:11:11:11",
"ip-address": "192.168.225.10", "state": 0, "subnet-id": 1, "valid-lft":
4000 }, "command": "lease4-update", "service":[ "dhcp4" ] }
2018-10-09 08:12:04.743 DEBUG [kea-dhcp4.callouts/2474] HOOKS_CALLOUT_CALLED
hooks library with index 2 has called a callout on hook leases4_committed
that has address 0x7f6dbbd1ca10 (callout duration: 0.441 ms)
2018-10-09 08:12:04.743 DEBUG [kea-dhcp4.callouts/2474]
HOOKS_CALLOUTS_COMPLETE completed callouts for hook leases4_committed (total
callouts duration: 0.441 ms)
2018-10-09 08:12:04.743 DEBUG [kea-dhcp4.hooks/2474]
DHCP4_HOOK_LEASES4_COMMITTED_PARK [hwtype=1 00:00:00:11:11:11], cid=[no
info], tid=0x1701b4b9: packet is parked, because a callout set the next step
to PARK
2018-10-09 08:12:05.744 DEBUG [kea-dhcp4.http/2474]
HTTP_SERVER_RESPONSE_RECEIVED received HTTP response from
http://192.168.62.5:8080/
2018-10-09 08:12:05.744 DEBUG [kea-dhcp4.http/2474]
HTTP_SERVER_RESPONSE_RECEIVED_DETAILS detailed information about well formed
response received from http://192.168.62.5:8080/:
HTTP/1.1 200 OK
Content-Length: 140
Content-Type: application/json
Date: Tue, 09 Oct 2018 06:12:04 GMT

[ { "result": 1, "text": "unable to forward command to the dhcp4 service: No
such file or directory. The server is likely to be offline" } ]
2018-10-09 08:12:05.745 WARN  [kea-dhcp4.ha-hooks/2474]
HA_LEASE_UPDATE_FAILED [hwtype=1 00:00:00:11:11:11], cid=[no info],
tid=0x1701b4b9: lease update to server1 (http://192.168.62.5:8080/) failed:
unable to forward command to the dhcp4 service: No such file or directory.
The server is likely to be offline, error code 1
2018-10-09 08:12:05.745 DEBUG [kea-dhcp4.http/2474] HTTP_CLIENT_REQUEST_SEND
sending HTTP request POST / HTTP/1.1 to http://192.168.62.5:8080/
2018-10-09 08:12:05.745 DEBUG [kea-dhcp4.http/2474]
HTTP_CLIENT_REQUEST_SEND_DETAILS detailed information about request sent to
http://192.168.62.5:8080/:
-----Ursprüngliche Nachricht-----
Von: Marcin Siodelski <marcin at isc.org> 
Gesendet: Montag, 8. Oktober 2018 20:10
An: sven.roehrig at web.de; kea-users at lists.isc.org
Betreff: Re: [Kea-users] HA Load Balancing not working

Hello,

First of all, please note that the HA time values, i.e.
"heartbeat-delay", "max-ack-delay" and "max-response-delay" are specified in
milliseconds. Therefore, in your case heartbeat messages will be sent every
10ms, which is very high frequency potentially impacting server's
performance. Also, "max-ack-delay" being a time after which the server
considers the DHCP packet to not be answered by the partner is also very low
in your case. If these low values are provided for testing purposes only,
this is fine.

I am guessing the problem whereby you don't observe transition of the
surviving server from "load-balancing" to "partner-down" may be caused by
the fact that you don't simulate different clients but only a single client.

Your setting of "max-unacked-messages" of 10 means that the surviving server
will be watching traffic that should be processed by the offline partner and
it expects at least 10 messages from different clients to not be answered
before it transitions to "partner-down". If you're sending DHCP messages
from a single MAC address it counts as one client.
Try to lower the value of "max-unacked-messages" to 1 or even set it to
0 to disable this mechanism causing the surviving server to transition to
the "partner-down" state when it sees heartbeats to fail.

If your test tool allows for simulating many different clients, that's even
better, but the number of different clients should be at least 20.
That way, 10 should send DHCP queries to the dead server.

Kind Regards,
Marcin Siodelski
ISC DHCP Engineering

On 08.10.2018 15:07, sven.roehrig at web.de wrote:
>  
> 
>  
> 
> Hi,
> 
> i have a setup with 2 KEA servers in load-balancing configuration. 
> Both server are working when active but when I shutdown one server to 
> simulate an error I do get an OFFER but REQUESTS are not answered.
> 
> Do I have a wrong understanding on how the HA load-balancing works or 
> maybe I have  a configuration issue. I expect server1 to enter 
> partner-down state but I don´t see anything on logs except “The server 
> is likely to be offline, error code 1”.
> 
> Why gets a request parked when a partner state is down “packet is 
> parked, because a callout set the next step to PARK”?
> 
>  
> 
> "high-availability": [ {
> 
>                                                                
> "this-server-name": "server1",
> 
>                                                                 "mode":
> "load-balancing",
> 
>                                                                
> "heartbeat-delay": 10,
> 
>                                                                
> "max-ack-delay": 10,
> 
>                                                                
> "max-response-delay": 60,
> 
>                                                                
> "max-unacked-messages": 10,
> 
>                                                                 
> "peers": [
> 
>
                                                                            
    
> {
> 
>
                                                                            
   
> "name": "server1",
> 
>
                                                                            
   
> "url": "http://192.168.62.5:8080/",
> 
>                                         
>                                        "role": "primary",
> 
>
                                                                            
   
> "auto-failover": true
> 
>
                                                                            
   
> },
> 
>            
>                                                                     {
> 
>
                                                                            
   
> "name": "server2",
> 
>
                                                                            
   
> "url": "http://192.168.62.6:8080/",
> 
>
                                                                            
   
> "role": "secondary",
> 
>
                                                                            
   
> "auto-failover": true
> 
>                       
>                                                          }
> 
>                                                                 ]
> 
>                                                                 } ]
> 
>  
> 
>  
> 
> "high-availability": [ {
> 
>                                      
>                           "this-server-name": "server2",
> 
>                                                                 "mode":
> "load-balancing",
> 
>                                                                
> "heartbeat-delay": 10,
> 
>                      
>                                           "max-ack-delay": 10,
> 
>                                                                
> "max-response-delay": 60,
> 
>                                                                
> "max-unacked-messages": 10,
> 
>                                                                 
> "peers": [
> 
>
                                                                            
    
> {
> 
>
                                                                            
   
> "name": "server1",
> 
>
                                                                            
   
> "url": "http://192.168.62.5:8080/",
> 
>
                                                                            
   
> "role": "primary",
> 
>                                         
>                                        "auto-failover": true
> 
>
                                                                            
   
> },
> 
>
                                                                            
   
> {
> 
>                             
>                                                    "name": "server2",
> 
>
                                                                            
   
> "url": "http://192.168.62.6:8080/",
> 
>                                                                      
>           "role": "secondary",
> 
>
                                                                            
   
> "auto-failover": true
> 
>
                                                                            
   
> }
> 
>                                                                 ]
> 
>  
> 
>  
> 
> ./dhtest -i ens18 -m 00:00:00:11:11:12
> 
> DHCP discover sent        - Client MAC : 00:00:00:11:11:12
> 
> DHCP offer received      - Offered IP : 192.168.225.10
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
> DHCP request sent         - Client MAC : 00:00:00:11:11:12
> 
>  
> 
> 2018-10-08 14:50:11.639 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:13.641 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:15.645 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:17.648 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:19.651 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:21.654 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:23.657 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:25.660 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:27.664 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:29.667 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:31.670 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:33.673 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:35.676 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:37.679 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:39.682 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:41.476 INFO  [kea-dhcp4.options/1564] EVAL_RESULT 
> Expression CLASS-CPE evaluated to 1
> 
> 2018-10-08 14:50:41.476 INFO  [kea-dhcp4.leases/1564] 
> DHCP4_LEASE_ADVERT
> [hwtype=1 00:00:00:11:11:12], cid=[no info], tid=0xa4da4cd: lease
> 192.168.225.10 will be advertised
> 
> 2018-10-08 14:50:41.477 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:41.478 INFO  [kea-dhcp4.options/1564] EVAL_RESULT 
> Expression CLASS-CPE evaluated to 1
> 
> 2018-10-08 14:50:41.481 INFO  [kea-dhcp4.leases/1564] 
> DHCP4_LEASE_ALLOC
> [hwtype=1 00:00:00:11:11:12], cid=[no info], tid=0xa4da4cd: lease
> 192.168.225.10 has been allocated
> 
> 2018-10-08 14:50:42.483 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_LEASE_UPDATE_FAILED [hwtype=1 00:00:00:11:11:12], cid=[no info],
> tid=0xa4da4cd: lease update to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:43.484 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:45.488 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:45.700 INFO  [kea-dhcp4.options/1564] EVAL_RESULT 
> Expression CLASS-CPE evaluated to 1
> 
> 2018-10-08 14:50:45.712 INFO  [kea-dhcp4.leases/1564] 
> DHCP4_LEASE_ALLOC
> [hwtype=1 00:00:00:11:11:12], cid=[no info], tid=0xa4da4cd: lease
> 192.168.225.10 has been allocated
> 
> 2018-10-08 14:50:46.713 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_LEASE_UPDATE_FAILED [hwtype=1 00:00:00:11:11:12], cid=[no info],
> tid=0xa4da4cd: lease update to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:47.715 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:49.717 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:50.418 INFO  [kea-dhcp4.options/1564] EVAL_RESULT 
> Expression CLASS-CPE evaluated to 1
> 
> 2018-10-08 14:50:50.434 INFO  [kea-dhcp4.leases/1564] 
> DHCP4_LEASE_ALLOC
> [hwtype=1 00:00:00:11:11:12], cid=[no info], tid=0xa4da4cd: lease
> 192.168.225.10 has been allocated
> 
> 2018-10-08 14:50:51.435 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_LEASE_UPDATE_FAILED [hwtype=1 00:00:00:11:11:12], cid=[no info],
> tid=0xa4da4cd: lease update to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
> 2018-10-08 14:50:52.437 WARN  [kea-dhcp4.ha-hooks/1564] 
> HA_HEARTBEAT_FAILED heartbeat to server1 (http://192.168.62.5:8080/)
> failed: unable to forward command to the dhcp4 service: No such file 
> or directory. The server is likely to be offline, error code 1
> 
>  
> 
>  
> 
>  
> 
>  
> 
>  
> 
>  
> 
> 2018-10-08 15:05:35.327 DEBUG [kea-dhcp4.packets/1602] 
> DHCP4_SUBNET_SELECTED [hwtype=1 00:00:00:11:11:12], cid=[no info],
> tid=0x6569ccdb: the subnet with ID 1 was selected for client 
> assignments
> 
> 2018-10-08 15:05:35.327 DEBUG [kea-dhcp4.packets/1602] 
> DHCP4_SUBNET_DATA
> [hwtype=1 00:00:00:11:11:12], cid=[no info], tid=0x6569ccdb: the 
> selected subnet details: 192.168.225.0/24
> 
> 2018-10-08 15:05:35.327 DEBUG [kea-dhcp4.hosts/1602] 
> HOSTS_CFG_GET_ALL_IDENTIFIER get all hosts with reservations using
> identifier: hwaddr=000000111112
> 
> 2018-10-08 15:05:35.327 DEBUG [kea-dhcp4.hosts/1602] 
> HOSTS_CFG_GET_ALL_IDENTIFIER_COUNT using identifier 
> hwaddr=000000111112, found 0 host(s)
> 
> 2018-10-08 15:05:35.327 DEBUG [kea-dhcp4.dhcp4/1602] 
> DHCP4_CLASS_ASSIGNED [hwtype=1 00:00:00:11:11:12], cid=[no info],
> tid=0x6569ccdb: client packet has been assigned to the following
> class(es): UNKNOWN
> 
> 2018-10-08 15:05:35.327 DEBUG [kea-dhcp4.dhcp4/1602] 
> DHCP4_CLASS_ASSIGNED [hwtype=1 00:00:00:11:11:12], cid=[no info],
> tid=0x6569ccdb: client packet has been assigned to the following
> class(es): HA_server2, ALL, CLASS-CPE, UNKNOWN
> 
> 2018-10-08 15:05:35.327 DEBUG [kea-dhcp4.ddns/1602] 
> DHCP4_CLIENT_HOSTNAME_PROCESS [hwtype=1 00:00:00:11:11:12], cid=[no 
> info], tid=0x6569ccdb: processing client's Hostname option
> 
> 2018-10-08 15:05:35.328 DEBUG [kea-dhcp4.dhcpsrv/1602] 
> DHCPSRV_MYSQL_GET_HWADDR obtaining IPv4 leases for hardware address
> hwtype=1 00:00:00:11:11:12
> 
> 2018-10-08 15:05:35.328 DEBUG [kea-dhcp4.hosts/1602]
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4 get one host with reservation for 
> subnet id 1 and IPv4 address 192.168.225.10
> 
> 2018-10-08 15:05:35.328 DEBUG [kea-dhcp4.hosts/1602]
> HOSTS_CFG_GET_ALL_ADDRESS4 get all hosts with reservations for IPv4 
> address 192.168.225.10
> 
> 2018-10-08 15:05:35.328 DEBUG [kea-dhcp4.hosts/1602] 
> HOSTS_CFG_GET_ALL_ADDRESS4_COUNT using address 192.168.225.10, found 0
> host(s)
> 
> 2018-10-08 15:05:35.328 DEBUG [kea-dhcp4.hosts/1602] 
> HOSTS_CFG_GET_ONE_SUBNET_ID_ADDRESS4_NULL host not found using subnet 
> id
> 1 and address 192.168.225.10
> 
> 2018-10-08 15:05:35.328 DEBUG [kea-dhcp4.hosts/1602]
> HOSTS_MGR_ALTERNATE_GET4_SUBNET_ID_ADDRESS4 trying alternate sources 
> for host using subnet id 1 and address 192.168.225.10
> 
> 2018-10-08 15:05:35.329 DEBUG [kea-dhcp4.dhcpsrv/1602]
> DHCPSRV_MYSQL_GET_ADDR4 obtaining IPv4 lease for address 
> 192.168.225.10
> 
> 2018-10-08 15:05:35.329 DEBUG [kea-dhcp4.alloc-engine/1602] 
> ALLOC_ENGINE_V4_REQUEST_EXTEND_LEASE [hwtype=1 00:00:00:11:11:12], 
> cid=[no info], tid=0x6569ccdb: extending lifetime of the lease for 
> address 192.168.225.10
> 
> 2018-10-08 15:05:35.329 DEBUG [kea-dhcp4.dhcpsrv/1602]
> DHCPSRV_MYSQL_UPDATE_ADDR4 updating IPv4 lease for address 
> 192.168.225.10
> 
> 2018-10-08 15:05:35.332 INFO  [kea-dhcp4.leases/1602] 
> DHCP4_LEASE_ALLOC
> [hwtype=1 00:00:00:11:11:12], cid=[no info], tid=0x6569ccdb: lease
> 192.168.225.10 has been allocated
> 
> 2018-10-08 15:05:35.332 DEBUG [kea-dhcp4.dhcp4/1602] 
> DHCP4_CLIENTID_IGNORED_FOR_LEASES [hwtype=1 00:00:00:11:11:12], 
> cid=[no info], tid=0x6569ccdb: not using client identifier for lease 
> allocation for subnet 1
> 
> 2018-10-08 15:05:35.333 DEBUG [kea-dhcp4.callouts/1602] 
> HOOKS_CALLOUTS_BEGIN begin all callouts for hook leases4_committed
> 
> 2018-10-08 15:05:35.333 DEBUG [kea-dhcp4.http/1602] 
> HTTP_CLIENT_REQUEST_SEND sending HTTP request POST / HTTP/1.1 to 
> http://192.168.62.5:8080/
> 
> 2018-10-08 15:05:35.333 DEBUG [kea-dhcp4.http/1602] 
> HTTP_CLIENT_REQUEST_SEND_DETAILS detailed information about request 
> sent to http://192.168.62.5:8080/:
> 
> POST / HTTP/1.1
> 
> Content-Length: 283
> 
> Content-Type: application/json
> 
>  
> 
> { "arguments": { "expire": 1539007935, "force-create": true, "fqdn-fwd":
> false, "fqdn-rev": false, "hostname": "", "hw-address":
> "00:00:00:11:11:12", "ip-address": "192.168.225.10", "state": 0,
> "subnet-id": 1, "valid-lft": 4000 }, "command": "lease4-update", 
> "service":[ "dhcp4" ] }
> 
> 2018-10-08 15:05:35.333 DEBUG [kea-dhcp4.callouts/1602] 
> HOOKS_CALLOUT_CALLED hooks library with index 2 has called a callout 
> on hook leases4_committed that has address 0x7fc94ef83a10 (callout
> duration: 0.542 ms)
> 
> 2018-10-08 15:05:35.334 DEBUG [kea-dhcp4.callouts/1602] 
> HOOKS_CALLOUTS_COMPLETE completed callouts for hook leases4_committed 
> (total callouts duration: 0.542 ms)
> 
> 2018-10-08 15:05:35.334 DEBUG [kea-dhcp4.hooks/1602] 
> DHCP4_HOOK_LEASES4_COMMITTED_PARK [hwtype=1 00:00:00:11:11:12], 
> cid=[no info], tid=0x6569ccdb: packet is parked, because a callout set 
> the next step to PARK
> 
> 2018-10-08 15:05:36.335 DEBUG [kea-dhcp4.http/1602] 
> HTTP_SERVER_RESPONSE_RECEIVED received HTTP response from 
> http://192.168.62.5:8080/
> 
> 2018-10-08 15:05:36.336 DEBUG [kea-dhcp4.http/1602] 
> HTTP_SERVER_RESPONSE_RECEIVED_DETAILS detailed information about well 
> formed response received from http://192.168.62.5:8080/:
> 
> HTTP/1.1 200 OK
> 
> Content-Length: 140
> 
> Content-Type: application/json
> 
> Date: Mon, 08 Oct 2018 13:05:35 GMT
> 
>  
> 
> [ { "result": 1, "text": "unable to forward command to the dhcp4
> service: No such file or directory. The server is likely to be 
> offline" } ]
> 
> 
> 
> _______________________________________________
> Kea-users mailing list
> Kea-users at lists.isc.org
> https://lists.isc.org/mailman/listinfo/kea-users
> 




More information about the Kea-users mailing list