KEA service stopping through the day
-
@bcdouglas said in KEA service stopping through the day:
12:11:00
What is shown at that moment in the system log ? DHCP log ? Was the interface (LAN ?) disconnected ? System services restarted ?
-
I too have this issue.
Under "Services Status" - Kea DHCP service shows stopped. Starting it has no effect.
I already deleted the Watchdog entry for ISC DHCP as it was filling the system log with messages @bcdouglas posted.System log for DHCP:
Nov 13 13:07:53 kea-dhcp4 32826 ERROR [kea-dhcp4.dhcp4.0x1c655d812000] DHCP4_INIT_FAIL failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable
AND
Nov 13 13:07:53 kea-dhcp4 32826 WARN [kea-dhcp4.dhcp4.0x1c655d812000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first. Nov 13 13:07:53 kea-dhcp4 32826 WARN [kea-dhcp4.dhcpsrv.0x1c655d812000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled.
-
@bartkowski said in KEA service stopping through the day:
System log for DHCP:
Nov 13 13:07:53 kea-dhcp4 32826 ERROR [kea-dhcp4.dhcp4.0x1c655d812000] DHCP4_INIT_FAIL failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable
Is the file
/tmp/kea4-ctrl-socket.lock
still there? If so, if you remove it (e.g.rm /tmp/kea4-ctrl-socket.lock
) and then restart Kea, does it start and stay running? -
@jimp I ran the rm command without checking if the file still exists and then switched to Kea DHCP and the service is running now. I'll post if it stops again, but this is a good sign. Thank you.
-
@bartkowski said in KEA service stopping through the day:
@jimp I ran the rm command without checking if the file still exists and then switched to Kea DHCP and the service is running now. I'll post if it stops again, but this is a good sign. Thank you.
If it happens again look back farther in the log for other errors. Something had to have made it fail and leave that lock file behind.
Though something should probably be cleanup up that socket lock to stop it from being blocked in the way you encountered.
EDIT: I created a Redmine issue for that problem case: https://redmine.pfsense.org/issues/14977
-
-
@jimp said in KEA service stopping through the day:
If it happens again look back farther in the log for other errors. Something had to have made it fail and leave that lock file behind.
kea pocess ID 66699 runs fine :
<134>1 2023-11-13T12:27:46.196757+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_LEASE_ALLOC [hwtype=1 f0:03:8c:bd:82:51], cid=[01:f0:03:8c:bd:82:51], tid=0xe6ad31c9: lease 192.168.1.26 has been allocated for 86400 seconds <134>1 2023-11-13T12:27:53.094095+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_lan_0 evaluated to 1 <134>1 2023-11-13T12:27:53.094150+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt2_0 evaluated to 1 <134>1 2023-11-13T12:27:53.094186+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt1_0 evaluated to 1 <134>1 2023-11-13T12:27:53.094393+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_INIT_REBOOT [hwtype=1 a4:bb:6d:ba:0a:cc], cid=[01:a4:bb:6d:ba:0a:cc], tid=0x8b206146: client is in INIT-REBOOT state and requests address 192.168.1.7 <134>1 2023-11-13T12:27:53.094659+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_LEASE_ALLOC [hwtype=1 a4:bb:6d:ba:0a:cc], cid=[01:a4:bb:6d:ba:0a:cc], tid=0x8b206146: lease 192.168.1.7 has been allocated for 86400 seconds <134>1 2023-11-13T12:27:53.182388+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_lan_0 evaluated to 1 <134>1 2023-11-13T12:27:53.182435+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt2_0 evaluated to 1 <134>1 2023-11-13T12:27:53.182470+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt1_0 evaluated to 1 <134>1 2023-11-13T12:27:53.182640+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_INIT_REBOOT [hwtype=1 a4:bb:6d:ba:0a:cc], cid=[01:a4:bb:6d:ba:0a:cc], tid=0x191ea2: client is in INIT-REBOOT state and requests address 192.168.1.7 <134>1 2023-11-13T12:27:53.182865+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_LEASE_ALLOC [hwtype=1 a4:bb:6d:ba:0a:cc], cid=[01:a4:bb:6d:ba:0a:cc], tid=0x191ea2: lease 192.168.1.7 has been allocated for 86400 seconds <134>1 2023-11-13T12:28:12.056238+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_lan_0 evaluated to 1 <134>1 2023-11-13T12:28:12.056365+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt2_0 evaluated to 1 <134>1 2023-11-13T12:28:12.056494+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt1_0 evaluated to 1 <134>1 2023-11-13T12:28:12.057010+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_INIT_REBOOT [hwtype=1 f0:03:8c:bd:82:51], cid=[01:f0:03:8c:bd:82:51], tid=0x9fed9b30: client is in INIT-REBOOT state and requests address 192.168.1.26 <134>1 2023-11-13T12:28:12.057586+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_LEASE_ALLOC [hwtype=1 f0:03:8c:bd:82:51], cid=[01:f0:03:8c:bd:82:51], tid=0x9fed9b30: lease 192.168.1.26 has been allocated for 86400 seconds
At this moment, I edited some Unboud (resolver) settings, as a result DHCP (kea) got restarted ( ? ):
A new process is created : 36914:<134>1 2023-11-13T12:29:48.269908+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.hosts.0x2aa006212000] HOSTS_BACKENDS_REGISTERED the following host backend types are available: <132>1 2023-11-13T12:29:48.273600+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - WARN [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled. <132>1 2023-11-13T12:29:48.275977+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - WARN [kea-dhcp4.dhcp4.0x2aa006212000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first. <134>1 2023-11-13T12:29:48.276515+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0 <134>1 2023-11-13T12:29:48.313747+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc1 <134>1 2023-11-13T12:29:48.313806+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc2 <134>1 2023-11-13T12:29:48.313844+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using default socket type raw <134>1 2023-11-13T12:29:48.316396+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.hooks.0x2aa006212000] HOOKS_LIBRARY_CLOSED hooks library /usr/local/lib/kea/hooks/libdhcp_lease_cmds.so successfully closed <134>1 2023-11-13T12:29:48.317096+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.1.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:29:48.320114+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.2.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:29:48.320724+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.100.0/24 with params: valid-lifetime=7200 <134>1 2023-11-13T12:29:48.322962+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_SOCKET_TYPE_SELECT using socket type raw <134>1 2023-11-13T12:29:48.323307+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0 <134>1 2023-11-13T12:29:48.323345+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc1 <134>1 2023-11-13T12:29:48.323390+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc2 <134>1 2023-11-13T12:29:48.323427+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - INFO [kea-dhcp4.dhcpsrv.0x2aa006212000] DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using default socket type raw <131>1 2023-11-13T12:29:48.323711+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - ERROR [kea-dhcp4.dhcp4.0x2aa006212000] DHCP4_PARSER_COMMIT_FAIL parser failed to commit changes: cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable <131>1 2023-11-13T12:29:48.324342+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - ERROR [kea-dhcp4.dhcp4.0x2aa006212000] DHCP4_CONFIG_LOAD_FAIL configuration error using file: /usr/local/etc/kea/kea-dhcp4.conf, reason: cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable <131>1 2023-11-13T12:29:48.324808+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 36914 - - ERROR [kea-dhcp4.dhcp4.0x2aa006212000] DHCP4_INIT_FAIL failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable
Take note at the end of 36914 : it failed , as 66699 is still running and doing its job.
<134>1 2023-11-13T12:29:48.683307+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.hosts.0x31db2a812000] HOSTS_BACKENDS_REGISTERED the following host backend types are available: <132>1 2023-11-13T12:29:48.685062+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - WARN [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled. <132>1 2023-11-13T12:29:48.685672+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - WARN [kea-dhcp4.dhcp4.0x31db2a812000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first. <134>1 2023-11-13T12:29:48.689584+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0 <134>1 2023-11-13T12:29:48.689821+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc1 <134>1 2023-11-13T12:29:48.689924+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc2 <134>1 2023-11-13T12:29:48.690030+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using default socket type raw <134>1 2023-11-13T12:29:48.692835+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.hooks.0x31db2a812000] HOOKS_LIBRARY_CLOSED hooks library /usr/local/lib/kea/hooks/libdhcp_lease_cmds.so successfully closed <134>1 2023-11-13T12:29:48.693681+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.1.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:29:48.696870+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.2.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:29:48.697584+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.100.0/24 with params: valid-lifetime=7200 <134>1 2023-11-13T12:29:48.699934+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_SOCKET_TYPE_SELECT using socket type raw <134>1 2023-11-13T12:29:48.700783+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0 <134>1 2023-11-13T12:29:48.700910+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc1 <134>1 2023-11-13T12:29:48.701014+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc2 <134>1 2023-11-13T12:29:48.701113+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - INFO [kea-dhcp4.dhcpsrv.0x31db2a812000] DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using default socket type raw <131>1 2023-11-13T12:29:48.701479+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - ERROR [kea-dhcp4.dhcp4.0x31db2a812000] DHCP4_PARSER_COMMIT_FAIL parser failed to commit changes: cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable <131>1 2023-11-13T12:29:48.702220+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - ERROR [kea-dhcp4.dhcp4.0x31db2a812000] DHCP4_CONFIG_LOAD_FAIL configuration error using file: /usr/local/etc/kea/kea-dhcp4.conf, reason: cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable <131>1 2023-11-13T12:29:48.702769+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 57958 - - ERROR [kea-dhcp4.dhcp4.0x31db2a812000] DHCP4_INIT_FAIL failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable
I've restarted kea on the dash board GUI, as it was signalled 'stopped'.
Take note at the end of 57958 : it failed , as 66699 is still running and doing its job.<134>1 2023-11-13T12:29:57.883187+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_lan_0 evaluated to 1 <134>1 2023-11-13T12:29:57.883236+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt2_0 evaluated to 1 <134>1 2023-11-13T12:29:57.883270+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt1_0 evaluated to 1 <134>1 2023-11-13T12:30:52.944681+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.hosts.0x2c2191012000] HOSTS_BACKENDS_REGISTERED the following host backend types are available: <132>1 2023-11-13T12:30:52.946233+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - WARN [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled. <132>1 2023-11-13T12:30:52.946413+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - WARN [kea-dhcp4.dhcp4.0x2c2191012000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first. <134>1 2023-11-13T12:30:52.946581+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0 <134>1 2023-11-13T12:30:52.946701+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc1 <134>1 2023-11-13T12:30:52.946808+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc2 <134>1 2023-11-13T12:30:52.946913+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using default socket type raw <134>1 2023-11-13T12:30:52.949597+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.hooks.0x2c2191012000] HOOKS_LIBRARY_CLOSED hooks library /usr/local/lib/kea/hooks/libdhcp_lease_cmds.so successfully closed <134>1 2023-11-13T12:30:52.950462+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.1.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:30:52.953709+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.2.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:30:52.954451+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.100.0/24 with params: valid-lifetime=7200 <134>1 2023-11-13T12:30:52.956837+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_SOCKET_TYPE_SELECT using socket type raw <134>1 2023-11-13T12:30:52.957271+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0 <134>1 2023-11-13T12:30:52.957398+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc1 <134>1 2023-11-13T12:30:52.957509+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc2 <134>1 2023-11-13T12:30:52.957615+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - INFO [kea-dhcp4.dhcpsrv.0x2c2191012000] DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using default socket type raw <131>1 2023-11-13T12:30:52.957957+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - ERROR [kea-dhcp4.dhcp4.0x2c2191012000] DHCP4_PARSER_COMMIT_FAIL parser failed to commit changes: cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable <131>1 2023-11-13T12:30:52.958709+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - ERROR [kea-dhcp4.dhcp4.0x2c2191012000] DHCP4_CONFIG_LOAD_FAIL configuration error using file: /usr/local/etc/kea/kea-dhcp4.conf, reason: cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable <131>1 2023-11-13T12:30:52.959259+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 18912 - - ERROR [kea-dhcp4.dhcp4.0x2c2191012000] DHCP4_INIT_FAIL failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable
Take note at the end of 18912 : it failed to staet, as 66699 is still running and doing its job.
<134>1 2023-11-13T12:33:22.241513+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_lan_0 evaluated to 1 <134>1 2023-11-13T12:33:22.241642+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt2_0 evaluated to 1 <134>1 2023-11-13T12:33:22.241738+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt1_0 evaluated to 1 <134>1 2023-11-13T12:33:22.242195+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_INIT_REBOOT [hwtype=1 f0:03:8c:bd:82:51], cid=[01:f0:03:8c:bd:82:51], tid=0xf86e2fe4: client is in INIT-REBOOT state and requests address 192.168.1.26 <134>1 2023-11-13T12:33:22.242848+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_LEASE_ALLOC [hwtype=1 f0:03:8c:bd:82:51], cid=[01:f0:03:8c:bd:82:51], tid=0xf86e2fe4: lease 192.168.1.26 has been allocated for 86400 seconds <134>1 2023-11-13T12:33:24.233442+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_lan_0 evaluated to 1 <134>1 2023-11-13T12:33:24.233572+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt2_0 evaluated to 1 <134>1 2023-11-13T12:33:24.233667+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt1_0 evaluated to 1 <134>1 2023-11-13T12:33:24.234106+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_INIT_REBOOT [hwtype=1 f0:03:8c:bd:82:51], cid=[01:f0:03:8c:bd:82:51], tid=0xf86e2fe4: client is in INIT-REBOOT state and requests address 192.168.1.26 <134>1 2023-11-13T12:33:24.234730+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.leases.0xfd5a1a16d00] DHCP4_LEASE_ALLOC [hwtype=1 f0:03:8c:bd:82:51], cid=[01:f0:03:8c:bd:82:51], tid=0xf86e2fe4: lease 192.168.1.26 has been allocated for 86400 seconds <134>1 2023-11-13T12:33:40.932704+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_lan_0 evaluated to 1 <134>1 2023-11-13T12:33:40.932818+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt2_0 evaluated to 1 <134>1 2023-11-13T12:33:40.932903+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcpsrv.0xfd5a1a16d00] EVAL_RESULT Expression pool_opt1_0 evaluated to 1 <134>1 2023-11-13T12:34:12.983864+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.dhcp4.0xfd5a1a12000] DHCP4_SHUTDOWN server shutdown <134>1 2023-11-13T12:34:12.984898+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.lease-cmds-hooks.0xfd5a1a12000] LEASE_CMDS_DEINIT_OK unloading Lease Commands hooks library successful <134>1 2023-11-13T12:34:12.985316+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 66699 - - INFO [kea-dhcp4.hooks.0xfd5a1a12000] HOOKS_LIBRARY_CLOSED hooks library /usr/local/lib/kea/hooks/libdhcp_lease_cmds.so successfully closed
Now, I've killed 66699 manually.
Delete the lock file.
Started kea from the dashboard, kea process ID 81504 was created - and running since (already yesterday).<134>1 2023-11-13T12:34:35.689415+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.hosts.0x248197412000] HOSTS_BACKENDS_REGISTERED the following host backend types are available: <132>1 2023-11-13T12:34:35.691663+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - WARN [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled. <132>1 2023-11-13T12:34:35.694022+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - WARN [kea-dhcp4.dhcp4.0x248197412000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first. <134>1 2023-11-13T12:34:35.694348+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0 <134>1 2023-11-13T12:34:35.694646+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc1 <134>1 2023-11-13T12:34:35.696831+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc2 <134>1 2023-11-13T12:34:35.697090+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_SOCKET_TYPE_DEFAULT "dhcp-socket-type" not specified , using default socket type raw <134>1 2023-11-13T12:34:35.699837+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.hooks.0x248197412000] HOOKS_LIBRARY_CLOSED hooks library /usr/local/lib/kea/hooks/libdhcp_lease_cmds.so successfully closed <134>1 2023-11-13T12:34:35.700531+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.1.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:34:35.703503+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.2.0/24 with params: valid-lifetime=86400 <134>1 2023-11-13T12:34:35.704083+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_NEW_SUBNET4 a new subnet has been added to configuration: 192.168.100.0/24 with params: valid-lifetime=7200 <134>1 2023-11-13T12:34:35.706428+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_SOCKET_TYPE_SELECT using socket type raw <134>1 2023-11-13T12:34:35.707055+01:00 pfSense.brit-hotel-fumel.net kea-dhcp4 81504 - - INFO [kea-dhcp4.dhcpsrv.0x248197412000] DHCPSRV_CFGMGR_ADD_IFACE listening on interface igc0
66699 never died or someting like that.
There is no indication in the log file that the initial kea process 66699 actually received a 'stop' or 'kill' signal. -
Curious. I wonder what the contents of
/var/run/kea/kea-dhcp4.kea-dhcp4.pid
were during that time.I could maybe see something like that happening if the PID file in
/var/run/kea/kea-dhcp4.kea-dhcp4.pid
contained a PID that didn't match the daemon that was running. -
That's the one I'll be looking at - the content - the next time.
-
-
I switched to kea too, and it can't restart if it somehow gets hung or killed by unbound because of that lock file. Is there a way to add the rm command in the startup file of kea? What is the startup command for it, where is it located? I'd hate to have to run a cron job every minute just to remove it...
Thanks -
My KEA service (in an HA setup with two pfSense instances, both 2.7.2) kept behaving oddly, so I reverted to the ISC DHCP server which so far has been 100% stable. I don't think KEA is ready for prime time yet. Here's what I've observed:
- Once, I entered 10-15 static IP mappings, and the next day I noticed they were all gone.
- KEA server sometimes ran OK on both HA nodes, sometimes it stopped on one node but not on the other
- While adding static IP mappings today, I went back to edit a handful to enable Static ARP on the MASTER HA NODE. Reproduction steps:
** Click EDIT on a static DHCP rule.
** Click on static Arp checkbox to enable
** Hit Enter
** Go to Status -> DHCP Leases
** It's blank. The KEA Service on MASTER NODE had stopped itself with the error: "failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /tmp/kea4-ctrl-socket.lock, : Resource temporarily unavailable"
** This was very reproducible - Also, when doing CARP failover, sometimes KEA would stop on one node and not run on both after I disabled the forced-failover
Again, wayyyyy too many issues.
-
@Markito said in KEA service stopping through the day:
sometimes ran OK on both HA nodes
https://docs.netgate.com/pfsense/en/latest/releases/23-09.html#kea-dhcp-server-feature-preview-now-available
"Currently the Kea implementation lacks the following DHCP server features:
... High Availability Failover" -
@SteveITS Thanks :) I had not realized that.
-
@w0w
This can happen if you have switched from dhcpd to kea but have not changed the service watchdog. -
@jimp Today see TS state
unexpected state: NoState
and removing/tmp/kea4-ctrl-socket.lock
does no helpsomething new?
-
This issue should be handled with the 24.11-RC. Feedback on it would be helpful if you were hitting this previously.
-
@marcosm This issue is happening to me
a few nights prior i woke up to some "IOT" things flashing as they couldnt connect to their wifi.
and found i didnt have internet, however when i got up at 6 it was working again without user intervention so i am not sure..this morning i woke up to no "internet"
(some statically set things over ethernet were working, obv) but everything wifi was offline.on the router, kea ipv4 was offline i had to click the start button, for now i have installed the watch dog server to auto restart. id send logs if i knew where and which ones you wanted to help diag this? or if this is even related? (running 24.11)
best regards
-Rolder -
@darkrolder said in KEA service stopping through the day:
on the router, kea ipv4 was offline i had to click the start button, for now i have installed the watch dog server to auto restart. id send logs if i knew where and which ones you wanted to help diag this? or if this is even related? (running 24.11)
I have also had this experience on my Netgate 3100. Only details I could find in the logs was:
Dec 5 20:58:54 kernel pid 67465 (kea-dhcp4), jid 0, uid 0: exited on signal 6 (core dumped)
For some reason the kia-dhcp4 process does not seem to be generating any log entries on my device so really hard to work out if it's connected.
I have after reading a few posts increased the size of my DHCP pool in case some IoT devices are doing something odd (I saw this as a possibility in another thread.I am now in the monitoring phase but I would not have expected a DHCP service to fail so spectacularly if it ran out of addresses in it's pool to give out.
-
@DavidIr I don't think i have that many IOT devices, maybe 10-15? mostly light switches and my
cell phones, tv, etc. i have them on their own vlan with the DHCP pool size at about 150 IPs, my brother (IT admin) has suggested changing the DHCP lease from the default 2 hours to 24 hours. i have done this, so far so good. but its only been 1 day. s: only time will tell if this helps-Rolder
-
@DavidIr Did this happen on 24.11? The core dump file should be in /root - sharing that would help determine what happened.
-
@marcosm said in KEA service stopping through the day:
@DavidIr Did this happen on 24.11? The core dump file should be in /root - sharing that would help determine what happened.
Yes it did.
I assume the kea-dhcp4.core file?
I'm not familiar with these files - is it safe to just attach to the forum, or should I send in some other way?