Kea 1.4 load balancing fail over issue
Hi,
I have setup of Kea HA with load balancing mode with below config
` "hooks-libraries": [{ "library": "/usr/lib64/hooks/libdhcp_lease_cmds.so" },
{
"library": "/usr/lib64/hooks/libdhcp_stat_cmds.so"
},
{
"library": "/usr/lib64/hooks/libdhcp_ha.so",
"parameters": {
"high-availability": [{
"this-server-name": "secondary-server",
"mode": "load-balancing",
"heartbeat-interval": 10,
"max-response-delay": 5,
"max-ack-delay": 10,
"max-unacked-messages": 0,
"peers": [{
"name": "primary-server",
"url": "http://10.25.133.13:8080/",
"role": "primary",
"auto-failover": true
},
{
"name": "secondary-server",
"url": "http://10.25.133.12:8080/",
"role": "secondary",
"auto-failover": true
}
]
}]
}
}
]
},
`
when One of the server goes down, Failover not happening.The active server show the hearbeat warning but it not assigning lease to clients. I have stopped secondary server and tested with two client host Note : In configuration heartbeat interval is 10 seconds.
Setup : Two kea servers with separate DB.
Primary Server Log :
2018-10-22 05:54:09.914 INFO [kea-dhcp4.commands/30768] COMMAND_RECEIVED Received command 'ha-heartbeat'
2018-10-22 05:54:09.972 INFO [kea-dhcp4.commands/30768] COMMAND_RECEIVED Received command 'lease4-update'
2018-10-22 05:54:20.595 INFO [kea-dhcp4.commands/30768] COMMAND_RECEIVED Received command 'ha-heartbeat'
2018-10-22 05:54:20.627 INFO [kea-dhcp4.commands/30768] COMMAND_RECEIVED Received command 'lease4-update'
2018-10-22 05:54:20.901 INFO [kea-dhcp4.commands/30768] COMMAND_RECEIVED Received command 'lease4-update'
2018-10-22 05:54:23.898 INFO [kea-dhcp4.commands/30768] COMMAND_RECEIVED Received command 'lease4-update'
2018-10-22 05:54:30.910 INFO [kea-dhcp4.commands/30768] COMMAND_RECEIVED Received command 'ha-heartbeat'
2018-10-22 05:54:39.920 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:54:50.933 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:55:01.947 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:55:12.960 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:55:23.621 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:55:34.698 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:55:45.712 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:55:56.726 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:56:07.740 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:56:18.753 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:56:29.767 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:56:40.781 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:56:51.794 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:00.004 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:00.006 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x57bdcec7: lease 10.25.133.3 will be advertised
2018-10-22 05:57:02.063 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:02.065 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x57bdcec7: lease 10.25.133.3 has been allocated
2018-10-22 05:57:02.065 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:03.067 WARN [kea-dhcp4.ha-hooks/30768] HA_LEASE_UPDATE_COMMUNICATIONS_FAILED [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x57bdcec7: failed to communicate with (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:04.151 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:04.152 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x58bdcec7: lease 10.25.133.3 will be advertised
2018-10-22 05:57:08.215 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:08.218 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x58bdcec7: lease 10.25.133.3 has been allocated
2018-10-22 05:57:09.219 WARN [kea-dhcp4.ha-hooks/30768] HA_LEASE_UPDATE_COMMUNICATIONS_FAILED [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x58bdcec7: failed to communicate with (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:12.279 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:12.280 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x59bdcec7: lease 10.25.133.3 will be advertised
2018-10-22 05:57:12.280 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:20.353 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:20.355 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x59bdcec7: lease 10.25.133.3 has been allocated
2018-10-22 05:57:21.357 WARN [kea-dhcp4.ha-hooks/30768] HA_LEASE_UPDATE_COMMUNICATIONS_FAILED [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x59bdcec7: failed to communicate with (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:23.360 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:28.428 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:28.429 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x5abdcec7: lease 10.25.133.3 will be advertised
2018-10-22 05:57:34.436 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:44.449 WARN [kea-dhcp4.ha-hooks/30768] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to (http://10.25.133.12:8080/): Connection refused
2018-10-22 05:57:44.522 INFO [kea-dhcp4.options/30768] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:57:44.524 INFO [kea-dhcp4.leases/30768] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x5abdcec7: lease 10.25.133.3 has been allocated
2018-10-22 05:57:45.526 WARN [kea-dhcp4.ha-hooks/30768] HA_LEASE_UPDATE_COMMUNICATIONS_FAILED [hwtype=1 00:50:56:bd:ce:c7], cid=[no info], tid=0x5abdcec7: failed to communicate with (http://10.25.133.12:8080/): Connection refused
`
Secondary Server Log :
`2018-10-22 05:53:46.845 INFO [kea-dhcp4.stat-cmds-hooks/13245] STAT_CMDS_INIT_OK loading Stat Commands hooks library successful
2018-2018-10-22 05:53:46.845 INFO [kea-dhcp4.stat-cmds-hooks/13245] STAT_CMDS_INIT_OK loading Stat Commands hooks library successful
2018-10-22 05:53:46.845 INFO [kea-dhcp4.hooks/13245] HOOKS_LIBRARY_LOADED hooks library /usr/lib64/hooks/libdhcp_stat_cmds.so successfully loaded
2018-10-22 05:53:46.846 INFO [kea-dhcp4.ha-hooks/13245] HA_CONFIGURATION_SUCCESSFUL HA hook library has been successfully configured
2018-10-22 05:53:46.846 INFO [kea-dhcp4.ha-hooks/13245] HA_INIT_OK loading High Availability hooks library successful
2018-10-22 05:53:46.846 INFO [kea-dhcp4.hooks/13245] HOOKS_LIBRARY_LOADED hooks library /usr/lib64/hooks/libdhcp_ha.so successfully loaded
2018-10-22 05:53:46.846 INFO [kea-dhcp4.dhcp4/13245] DHCP4_CONFIG_COMPLETE DHCPv4 server has completed configuration: added IPv4 subnets: 1; DDNS: disabled
2018-10-22 05:53:46.846 INFO [kea-dhcp4.dhcpsrv/13245] DHCPSRV_MYSQL_DB opening MySQL lease database: connect-timeout=50 host=10.25.133.16 max-reconnect-tries=5 name=kea password=***** port=3306 reconnect-wait-time=10 request-timeout=120 tcp-keepalive=1 type=mysql universe=4 user=kea
2018-10-22 05:53:46.856 INFO [kea-dhcp4.hosts/13245] DHCPSRV_MYSQL_HOST_DB opening MySQL hosts database: connect-timeout=50 host=10.25.133.16 max-reconnect-tries=5 name=kea password=***** port=3306 reconnect-wait-time=10 request-timeout=120 tcp-keepalive=1 type=mysql universe=4 user=kea
2018-10-22 05:53:46.865 INFO [kea-dhcp4.ha-hooks/13245] HA_LOCAL_DHCP_DISABLE local DHCP service is disabled while the secondary-server. is in the WAITING state
2018-10-22 05:53:46.865 INFO [kea-dhcp4.ha-hooks/13245] HA_SERVICE_STARTED started high availability service in load-balancing mode as secondary server
2018-10-22 05:53:53.517 INFO [kea-dhcp4.commands/13245] COMMAND_RECEIVED Received command 'ha-heartbeat'
2018-10-22 05:53:59.525 INFO [kea-dhcp4.ha-hooks/13245] HA_STATE_TRANSITION server transitions from WAITING to SYNCING state, partner state is LOAD-BALANCING
2018-10-22 05:53:59.526 INFO [kea-dhcp4.ha-hooks/13245] HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the partner while in SYNCING state
2018-10-22 05:53:59.526 INFO [kea-dhcp4.ha-hooks/13245] HA_SYNC_START starting lease database synchronization with primary-server.
2018-10-22 05:53:59.532 INFO [kea-dhcp4.ha-hooks/13245] HA_SYNC_SUCCESSFUL lease database synchronization with primary-server. completed successfully in 6.051 ms
2018-10-22 05:53:59.532 INFO [kea-dhcp4.ha-hooks/13245] HA_STATE_TRANSITION server transitions from SYNCING to READY state, partner state is LOAD-BALANCING
2018-10-22 05:53:59.532 INFO [kea-dhcp4.ha-hooks/13245] HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the partner while in READY state
2018-10-22 05:53:59.532 INFO [kea-dhcp4.ha-hooks/13245] HA_STATE_TRANSITION server transitions from READY to LOAD-BALANCING state, partner state is LOAD-BALANCING
2018-10-22 05:53:59.532 INFO [kea-dhcp4.ha-hooks/13245] HA_LEASE_UPDATES_ENABLED lease updates will be sent to the partner while in LOAD-BALANCING state
2018-10-22 05:53:59.532 INFO [kea-dhcp4.ha-hooks/13245] HA_LOCAL_DHCP_ENABLE local DHCP service is enabled while the secondary-server. is in the LOAD-BALANCING state
2018-10-22 05:54:04.538 INFO [kea-dhcp4.commands/13245] COMMAND_RECEIVED Received command 'ha-heartbeat'
2018-10-22 05:54:07.908 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:54:07.910 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:e4:6c], cid=[no info], tid=0x57bde46c: lease 10.25.133.2 will be advertised
2018-10-22 05:54:09.966 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:54:09.970 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:e4:6c], cid=[no info], tid=0x57bde46c: lease 10.25.133.2 has been allocated
2018-10-22 05:54:15.982 INFO [kea-dhcp4.commands/13245] COMMAND_RECEIVED Received command 'ha-heartbeat'
2018-10-22 05:54:17.548 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:54:17.548 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression iPXE evaluated to 1
2018-10-22 05:54:17.550 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:e4:6c], cid=[01:00:50:56:bd:e4:6c], tid=0xa6ef2548: lease 10.25.133.2 will be advertised
2018-10-22 05:54:18.589 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:54:18.589 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression iPXE evaluated to 1
2018-10-22 05:54:18.591 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:e4:6c], cid=[01:00:50:56:bd:e4:6c], tid=0xa6ef2548: lease 10.25.133.2 will be advertised
2018-10-22 05:54:20.621 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:54:20.621 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression iPXE evaluated to 1
2018-10-22 05:54:20.625 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:e4:6c], cid=[01:00:50:56:bd:e4:6c], tid=0xa6ef2548: lease 10.25.133.2 has been allocated
2018-10-22 05:54:20.896 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression Legacy evaluated to 1
2018-10-22 05:54:20.896 INFO [kea-dhcp4.options/13245] EVAL_RESULT Expression iPXE evaluated to 1
2018-10-22 05:54:20.899 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:e4:6c], cid=[01:00:50:56:bd:e4:6c], tid=0xa6ef2548: lease 10.25.133.2 has been allocated
2018-10-22 05:54:23.894 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ADVERT [hwtype=1 00:50:56:bd:e4:6c], cid=[no info], tid=0x719e0c6e: lease 10.25.133.2 will be advertised
2018-10-22 05:54:23.896 INFO [kea-dhcp4.leases/13245] DHCP4_LEASE_ALLOC [hwtype=1 00:50:56:bd:e4:6c], cid=[no info], tid=0x719e0c6e: lease 10.25.133.2 has been allocated
2018-10-22 05:54:27.904 INFO [kea-dhcp4.commands/13245] COMMAND_RECEIVED Received command 'ha-heartbeat'
^C
# keactrl stop
INFO/keactrl: Stopping kea-dhcp4...
INFO/keactrl: Stopping kea-dhcp6...
INFO/keactrl: kea-dhcp-ddns isn't running.
INFO/keactrl: Stopping kea-ctrl-agent...`
fail-over not working? anyone aware feel free to suggest. Thanks