<div dir="ltr">The root cause is addressed.<div><br></div><div>2020-04-08 09:30:33.136 WARN [kea-dhcp4.ha-hooks/29601] HA_LEASE_UPDATE_FAILED [hwtype=1 00:15:65:98:c1:85], cid=[01:00:15:65:98:c1:85], tid=0xe088765b: lease update to server2 (<a href="http://172.16.232.20:8080/">http://172.16.232.20:8080/</a>) failed: The address 172.20.131.221 does not belong to subnet <a href="http://172.20.131.0/25">172.20.131.0/25</a>, subnet-id=18, error code 1<br>2020-04-08 09:30:33.529 INFO [kea-dhcp4.leases/29601] DHCP4_LEASE_ALLOC [hwtype=1 80:5e:c0:4c:28:52], cid=[01:80:5e:c0:4c:28:52], tid=0x45d82217: lease 172.20.137.66 has been allocated<br>2020-04-08 09:30:33.530 WARN [kea-dhcp4.ha-hooks/29601] HA_LEASE_UPDATE_FAILED [hwtype=1 00:15:65:90:e9:10], cid=[01:00:15:65:90:e9:10], tid=0x17253f72: lease update to server2 (<a href="http://172.16.232.20:8080/">http://172.16.232.20:8080/</a>) failed: The address 192.168.104.24 does not belong to subnet <a href="http://172.20.127.0/24">172.20.127.0/24</a>, subnet-id=14, error code 1<br></div><div><br></div><div>Because Master/slave node get different Subnet
sequence . So it makes subnet id inconsistent.</div><div><br></div><div>Just make sure master/slave get the same sequence of subnet. </div><div><br></div><div>Just keep the similar config file of master and slave node.</div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Tue, Apr 7, 2020 at 4:10 PM luckydog xf <<a href="mailto:luckydogxf@gmail.com">luckydogxf@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr">Sorry, it did not sync only once. It syned periodically.<div><br></div><div>### [root@keaslave1 ~]# grep synchronization /opt/kea-1.5.0/var/log/kea-dhcp4.log ####</div><div><br><div>2020-04-07 15:43:36.667 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 15:43:46.667 ERROR [kea-dhcp4.ha-hooks/2498] HA_SYNC_FAILED lease database synchronization with server1 failed: Connection timed out<br>2020-04-07 15:43:57.211 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 15:43:57.266 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_SUCCESSFUL lease database synchronization with server1 completed successfully in 55.718 ms<br>2020-04-07 15:44:30.241 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 15:44:40.241 ERROR [kea-dhcp4.ha-hooks/2498] HA_SYNC_FAILED lease database synchronization with server1 failed: Connection timed out<br>2020-04-07 15:44:50.255 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 15:45:00.255 ERROR [kea-dhcp4.ha-hooks/2498] HA_SYNC_FAILED lease database synchronization with server1 failed: Connection timed out<br>2020-04-07 15:45:10.792 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 15:45:10.848 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_SUCCESSFUL lease database synchronization with server1 completed successfully in 55.661 ms<br>2020-04-07 15:56:53.608 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 15:56:53.664 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_SUCCESSFUL lease database synchronization with server1 completed successfully in 56.517 ms<br>2020-04-07 15:57:16.573 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 15:57:16.630 INFO [kea-dhcp4.ha-hooks/2498] HA_SYNC_SUCCESSFUL lease database synchronization with server1 completed successfully in 56.862 ms<br></div></div><div>#</div><div><br></div><div>The point of sync were 15:43, 15:44, 14:45( retried due to connection timeout) and 15:56/57(retried again).</div><div><br></div><div>The interval is around 10 minutes, is is normal ?</div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Tue, Apr 7, 2020 at 2:42 PM luckydog xf <<a href="mailto:luckydogxf@gmail.com" target="_blank">luckydogxf@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr">Thanks, I double check it.<div>I set both server's clock and restart services. Now it seems it begins to sync lease data.</div><div><br></div><div><br></div><div>But in Standby node, it just synced only once.</div><div>------------------------</div><div>2020-04-07 14:38:06.230 INFO [kea-dhcp4.ha-hooks/1754] HA_STATE_TRANSITION server transitions from WAITING to SYNCING state, partner state is HOT-STANDBY<br>2020-04-07 14:38:06.230 INFO [kea-dhcp4.ha-hooks/1754] HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the partner while in SYNCING state<br>2020-04-07 14:38:06.230 INFO [kea-dhcp4.ha-hooks/1754] HA_SYNC_START starting lease database synchronization with server1<br>2020-04-07 14:38:06.279 INFO [kea-dhcp4.ha-hooks/1754] HA_LEASES_SYNC_LEASE_PAGE_RECEIVED received 500 leases from server1<br>2020-04-07 14:38:06.286 INFO [kea-dhcp4.ha-hooks/1754] HA_SYNC_SUCCESSFUL lease database synchronization with server1 completed successfully in 55.856 ms<br>2020-04-07 14:38:06.286 INFO [kea-dhcp4.ha-hooks/1754] HA_STATE_TRANSITION server transitions from SYNCING to READY state, partner state is HOT-STANDBY<br>2020-04-07 14:38:06.286 INFO [kea-dhcp4.ha-hooks/1754] HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the partner while in READY state<br>2020-04-07 14:38:06.286 INFO [kea-dhcp4.ha-hooks/1754] HA_STATE_TRANSITION server transitions from READY to HOT-STANDBY state, partner state is HOT-STANDBY<br>2020-04-07 14:38:06.286 INFO [kea-dhcp4.ha-hooks/1754] HA_LEASE_UPDATES_ENABLED lease updates will be sent to the partner while in HOT-STANDBY state<br>2020-04-07 14:38:06.286 INFO [kea-dhcp4.ha-hooks/1754] HA_LOCAL_DHCP_ENABLE local DHCP service is enabled while the server2 is in the HOT-STANDBY state<br>2020-04-07 14:38:13.399 INFO [kea-dhcp4.commands/1754] COMMAND_RECEIVED Received command 'ha-heartbeat'<br>2020-04-07 14:38:24.413 INFO [kea-dhcp4.commands/1754] COMMAND_RECEIVED Received command 'ha-heartbeat'<br>2020-04-07 14:38:29.239 INFO [kea-dhcp4.commands/1754] COMMAND_RECEIVED Received command 'lease4-update'<br>2020-04-07 14:38:29.239 ERROR [kea-dhcp4.callouts/1754] HOOKS_CALLOUT_ERROR error returned by callout on hook 2 registered by library with index $lease4_update (callout address 0x7faefd365ca0) (callout duration 0.065 ms)<br>2020-04-07 14:38:33.454 INFO [kea-dhcp4.commands/1754] COMMAND_RECEIVED Received command 'lease4-update'<br>2020-04-07 14:38:33.454 ERROR [kea-dhcp4.callouts/1754] HOOKS_CALLOUT_ERROR error returned by callout on hook 2 registered by library with index $lease4_update (callout address 0x7faefd365ca0) (callout duration 0.048 ms)<br>2020-04-07 14:38:34.177 INFO [kea-dhcp4.commands/1754] COMMAND_RECEIVED Received command 'lease4-update'<br>2020-04-07 14:38:34.177 ERROR [kea-dhcp4.callouts/1754] HOOKS_CALLOUT_ERROR error returned by callout on hook 2 registered by library with index $lease4_update (callout address 0x7faefd365ca0) (callout duration 0.048 ms)<br>2020-04-07 14:38:36.180 INFO [kea-dhcp4.commands/1754] COMMAND_RECEIVED Received command 'ha-heartbeat'<br>2020-04-07 14:38:37.922 INFO [kea-dhcp4.commands/1754] COMMAND_RECEIVED Received command 'lease4-update'<br>2020-04-07 14:38:37.922 ERROR [kea-dhcp4.callouts/1754] HOOKS_CALLOUT_ERROR error returned by callout on hook 2 registered by library with index $lease4_update (callout address 0x7faefd365ca0) (callout duration 0.052 ms)<br></div><div>--------------------</div><div><br></div><div>In primary node, it kept saying that lease data was synced.</div><div>---------</div><div>2020-04-07 14:39:46.012 INFO [kea-dhcp4.ha-hooks/28440] HA_SYNC_START starting lease database synchronization with server2<br>2020-04-07 14:39:46.061 INFO [kea-dhcp4.ha-hooks/28440] HA_SYNC_SUCCESSFUL lease database synchronization with server2 completed successfully in 48.493 ms<br>2020-04-07 14:39:57.605 INFO [kea-dhcp4.ha-hooks/28440] HA_SYNC_START starting lease database synchronization with server2<br>2020-04-07 14:39:57.658 INFO [kea-dhcp4.ha-hooks/28440] HA_SYNC_SUCCESSFUL lease database synchronization with server2 completed successfully in 52.490 ms<br>2020-04-07 14:40:20.289 INFO [kea-dhcp4.ha-hooks/28440] HA_SYNC_START starting lease database synchronization with server2<br></div><div>--------------</div><div><br></div><div>It seems that slave node failed to sync later due to unkown reason. </div><div><br></div><div>Here is part of my conf of both sides.</div><div><br></div><div>----------</div><div> {<br> "library": "/opt/kea-1.5.0/lib/hooks/libdhcp_stat_cmds.so"<br> },<br> {<br> "library": "/opt/kea-1.5.0/lib/hooks/libdhcp_lease_cmds.so"<br> },<br> {<br> "library": "/opt/kea-1.5.0/lib/hooks/libdhcp_ha.so",<br> "parameters": {<br> "high-availability": [ {<br> "this-server-name": "server2",<br> "mode": "hot-standby",<br> "heartbeat-delay": 10000,<br> "max-response-delay": 10000,<br> "max-ack-delay": 5000,<br> "max-unacked-clients": 5,<br><br> "send-lease-updates": true,<br> "sync-leases": true,<br> "sync-page-limit": 10000,<br> "sync-timeout": 30000,<br><br> "peers": [<br> {<br> "name": "server1",<br> "url": "<a href="http://172.16.232.18:8080/" target="_blank">http://172.16.232.18:8080/</a>",<br> "role": "primary",<br> "auto-failover": true<br> },<br> {<br> "name": "server2",<br> "url": "<a href="http://172.16.232.20:8080/" target="_blank">http://172.16.232.20:8080/</a>",<br> "role": "standby",<br> "auto-failover": true<br> }<br> ]<br> } ]<br> }<br> }<br> ],<br>------</div><div><br></div><div>Anything wrong ? Thanks,</div><div><br></div><div><br></div><div><br></div><div><br></div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Fri, Apr 3, 2020 at 7:26 PM Marcin Siodelski <<a href="mailto:marcin@isc.org" target="_blank">marcin@isc.org</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hello,<br>
<br>
The issue you're pointing at was merely to improve the logging of the<br>
time skew, partner's time and the local server's time, so you could more<br>
easily diagnose why the server decided to terminate the HA function. As<br>
far as I remember, it doesn't functionally change the server's behavior.<br>
Therefore, I think it must be something else.<br>
<br>
If you could provide us with the logs of BOTH DHCP servers it could shed<br>
some more light on the cauase of your problem.<br>
<br>
Kind Regards,<br>
<br>
Marcin Siodelski<br>
Sr. Software Engineer<br>
ISC<br>
<br>
On 03/04/2020 07:21, luckydog xf wrote:<br>
> I corrected both server's datetime and restarted both service of two<br>
> servers. But it still got the same error.<br>
> <br>
> <a href="https://gitlab.isc.org/isc-projects/kea/-/merge_requests/414" rel="noreferrer" target="_blank">https://gitlab.isc.org/isc-projects/kea/-/merge_requests/414</a> <br>
> <br>
> Seem a bug of v1.5.0. <br>
> <br>
> On Thu, Apr 2, 2020 at 6:34 PM Marcin Siodelski <<a href="mailto:marcin@isc.org" target="_blank">marcin@isc.org</a><br>
> <mailto:<a href="mailto:marcin@isc.org" target="_blank">marcin@isc.org</a>>> wrote:<br>
> <br>
> Hello,<br>
> <br>
> Thank you for your email. It would be useful to see the log from the<br>
> primary server to see why it went to the "terminated" state. The standby<br>
> server apparently transitioned to the "terminated" state seeing that the<br>
> partner is in that state. Note that the server which transitioned to the<br>
> "terminated" state (e.g. as a result of too high clock skew) will not<br>
> transition out of this state automatically, even if the clocks get<br>
> synchronized. It must be stopped and started again. Perhaps, the primary<br>
> server wasn't restarted after syncing the clocks?<br>
> <br>
> Marcin Siodelski<br>
> Sr. Software Engineer<br>
> ISC<br>
> <br>
> On 02/04/2020 10:36, luckydog xf wrote:<br>
> > Hi, list,<br>
> ><br>
> > I'm using Kea V1.5.0 and running two dhcp servers in Hot-standby<br>
> mode.<br>
> > My lease database is Memfile. I setup NTP for both servers. <br>
> ><br>
> > Here is part of my configuration, <br>
> > ===============<br>
> > "high-availability": [ {<br>
> > "this-server-name": "server2",<br>
> > "mode": "hot-standby",<br>
> > "heartbeat-delay": 10000,<br>
> > "max-response-delay": 10000,<br>
> > "max-ack-delay": 5000,<br>
> > "max-unacked-clients": 5,<br>
> ><br>
> > "send-lease-updates": true,<br>
> > "sync-leases": true,<br>
> > "sync-page-limit": 10000,<br>
> > "sync-timeout": 30000,<br>
> ><br>
> > "peers": [<br>
> > {<br>
> > "name": "server1",<br>
> > "url": "<a href="http://172.16.232.18:8080/" rel="noreferrer" target="_blank">http://172.16.232.18:8080/</a>",<br>
> > "role": "primary",<br>
> > "auto-failover": true<br>
> > },<br>
> > {<br>
> > "name": "server2",<br>
> > "url": "<a href="http://172.16.232.20:8080/" rel="noreferrer" target="_blank">http://172.16.232.20:8080/</a>",<br>
> > "role": "standby",<br>
> > "auto-failover": true<br>
> > }<br>
> > =============<br>
> ><br>
> > Yet on standby server ,it says that,<br>
> > ===============<br>
> > 2020-04-02 11:08:19.269 INFO [kea-dhcp4.ha-hooks/11468]<br>
> > HA_LOCAL_DHCP_DISABLE local DHCP service is disabled while the server2<br>
> > is in the WAITING state<br>
> > 2020-04-02 11:08:19.269 INFO [kea-dhcp4.ha-hooks/11468]<br>
> > HA_SERVICE_STARTED started high availability service in<br>
> hot-standby mode<br>
> > as standby server<br>
> > 2020-04-02 11:08:19.269 INFO [kea-dhcp4.dhcp4/11468]<br>
> DHCP4_STARTED Kea<br>
> > DHCPv4 server version 1.5.0 started<br>
> > 2020-04-02 11:08:31.283 INFO [kea-dhcp4.ha-hooks/11468]<br>
> > HA_STATE_TRANSITION server transitions from WAITING to TERMINATED<br>
> state,<br>
> > partner state is TERMINATED<br>
> > 2020-04-02 11:08:31.283 INFO [kea-dhcp4.ha-hooks/11468]<br>
> > HA_LEASE_UPDATES_DISABLED lease updates will not be sent to the<br>
> partner<br>
> > while in TERMINATED state<br>
> > 2020-04-02 11:08:31.283 INFO [kea-dhcp4.ha-hooks/11468]<br>
> > HA_LOCAL_DHCP_ENABLE local DHCP service is enabled while the<br>
> server2 is<br>
> > in the TERMINATED state<br>
> > 2020-04-02 11:08:31.283 ERROR [kea-dhcp4.ha-hooks/11468] HA_TERMINATED<br>
> > HA service terminated because of the unacceptable clock skew; fix the<br>
> > problem and restart!<br>
> ><br>
> > ============<br>
> ><br>
> > I'm sure two severs get correct date time. So what's the reason ?<br>
> ><br>
> > Is it related<br>
> > to <a href="https://gitlab.isc.org/isc-projects/kea/-/merge_requests/414" rel="noreferrer" target="_blank">https://gitlab.isc.org/isc-projects/kea/-/merge_requests/414</a> ?<br>
> ><br>
> > Thanks and take care.<br>
> ><br>
> > -hongquan<br>
> ><br>
> ><br>
> > _______________________________________________<br>
> > Kea-users mailing list<br>
> > <a href="mailto:Kea-users@lists.isc.org" target="_blank">Kea-users@lists.isc.org</a> <mailto:<a href="mailto:Kea-users@lists.isc.org" target="_blank">Kea-users@lists.isc.org</a>><br>
> > <a href="https://lists.isc.org/mailman/listinfo/kea-users" rel="noreferrer" target="_blank">https://lists.isc.org/mailman/listinfo/kea-users</a><br>
> ><br>
> <br>
<br>
</blockquote></div>
</blockquote></div>
</blockquote></div>