[Kea-users] debug logging for HA heartbeat

Fri Jan 28 14:58:55 UTC 2022

Is there a way to change the default ?

./src/lib/http/client.h: const RequestTimeout& request_timeout =
./src/lib/http/client.h: RequestTimeout(10000),

(although I agree that it should not take 10 sec ..)

> On 28/01/2022 15:38 veronique.lefebure at cern.ch wrote:
> 
> 
> Here is probably a hint for the problem as seen in the control agent logs:
> HTTP_CLIENT_REQUEST_TIMEOUT_OCCURRED
> and
> HTTP_CONNECTION_STOP
> 
> Next question is : how/where is the timeout of "10" defined ?
> 
> 2022-01-28 15:10:50.419 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CONNECTION_HANDSHAKE_START start TLS handshake with kea2 with timeout 10
> 2022-01-28 15:10:50.419 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CLIENT_REQUEST_TIMEOUT_OCCURRED HTTP request timeout occurred when communicating with (unknown address)
> 2022-01-28 15:10:50.419 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CONNECTION_STOP stopping HTTP connection from (unknown address)
> 2022-01-28 15:10:50.419 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CONNECTION_HANDSHAKE_START start TLS handshake with kea2 with timeout 10
> 2022-01-28 15:10:50.420 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CONNECTION_STOP stopping HTTP connection from (unknown address)
> 2022-01-28 15:10:50.421 INFO [kea-ctrl-agent.http/17978.140214125492416] HTTP_CONNECTION_HANDSHAKE_FAILED TLS handshake with (unknown address) failed with short read
> 2022-01-28 15:10:50.421 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CONNECTION_STOP stopping HTTP connection from (unknown address)
> 2022-01-28 15:10:50.494 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTPS_REQUEST_RECEIVE_START start receiving request from kea2
> 2022-01-28 15:10:50.494 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_DATA_RECEIVED received 146 bytes from kea2
> 2022-01-28 15:10:50.495 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CLIENT_REQUEST_RECEIVED received HTTP request from kea2
> 2022-01-28 15:10:50.495 DEBUG [kea-ctrl-agent.http/17978.140214125492416] HTTP_CLIENT_REQUEST_RECEIVED_DETAILS detailed information about well-formed request received from kea2:
> 
> > On 28/01/2022 13:11 Veronique Lefebure <veronique.lefebure at cern.ch> wrote:
> > 
> > 
> > Hi,
> > 
> > I would like to get a DEBUG logging each time a server receives a heartbeat from its partner, in a HA setup.
> > I have enabled DEBUG level 99 for kea-dhcp4.ha-hooks but it does not provide that info,
> > 
> > I am trying to understand why our standby server shows the following every 2 min:
> > 
> > 2022-01-28 13:02:30.869 WARN [kea-dhcp4.ha-hooks/22827.140145289767104] HA_HEARTBEAT_COMMUNICATIONS_FAILED failed to send heartbeat to kea1 (http://xx.253:9099/): Connection timed out
> > 2022-01-28 13:02:30.869 WARN [kea-dhcp4.ha-hooks/22827.140145289767104] HA_COMMUNICATION_INTERRUPTED communication with kea1 is interrupted
> > 
> > 
> > And the primary server then oscillates like this (we have only 1 client for now for test purpose):
> > 
> > 2022-01-28 13:06:31.887 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_STATE_TRANSITION server transitions from HOT-STANDBY to WAITING state, partner state is PARTNER-DOWN
> > 2022-01-28 13:06:31.887 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the partner while in WAITING state
> > 2022-01-28 13:06:31.887 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LOCAL_DHCP_DISABLE local DHCP service is disabled while the kea1 is in the WAITING state
> > 2022-01-28 13:06:31.887 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_STATE_TRANSITION server transitions from WAITING to SYNCING state, partner state is PARTNER-DOWN
> > 2022-01-28 13:06:31.887 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the partner while in SYNCING state
> > 2022-01-28 13:06:31.888 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_SYNC_START starting lease database synchronization with kea2
> > 2022-01-28 13:06:31.972 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LEASES_SYNC_LEASE_PAGE_RECEIVED received 1 leases from kea2
> > 2022-01-28 13:06:31.972 DEBUG [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LEASE_SYNC_STALE_LEASE4_SKIP skipping stale lease xx.xx.xx.xx in subnet 2156789248
> > 2022-01-28 13:06:31.975 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_SYNC_SUCCESSFUL lease database synchronization with kea2 completed successfully in 87.082 ms
> > 2022-01-28 13:06:31.976 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_STATE_TRANSITION server transitions from SYNCING to READY state, partner state is PARTNER-DOWN
> > 2022-01-28 13:06:31.976 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the partner while in READY state
> > 
> > 
> > 
> > 2022-01-28 13:06:52.532 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_STATE_TRANSITION server transitions from READY to HOT-STANDBY state, partner state is HOT-STANDBY
> > 2022-01-28 13:06:52.532 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LEASE_UPDATES_ENABLED lease updates will be sent to the partner while in HOT-STANDBY state
> > 2022-01-28 13:06:52.532 INFO [kea-dhcp4.ha-hooks/12849.140566551173312] HA_LOCAL_DHCP_ENABLE local DHCP service is enabled while the kea1 is in the HOT-STANDBY state
> > 
> > Thanks.
> > _______________________________________________
> > 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
> > Kea-users at lists.isc.org
> > https://lists.isc.org/mailman/listinfo/kea-users
> > 
> _______________________________________________
> 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
> Kea-users at lists.isc.org
> https://lists.isc.org/mailman/listinfo/kea-users
> 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.isc.org/pipermail/kea-users/attachments/20220128/1ee84931/attachment.htm>