Regression #15823
closedKea service is down and cannot be enabled after down event
0%
Description
Found KEA DHCP server down today, checked logs and noticed a down event.
Tried to enabled it again, and the same logs appeared about a cannot lock socket lockfile, /var/run/kea4-ctrl-socket.lock, : Resource temporarily unavailable
Logs:
2024-11-06T02:50:50.000-03:00 php-fpm35081: /rc.newwanip: Removing static route for monitor 8.8.4.4 and adding a new route through 192.168.255.233
2024-11-06T02:50:50.000-03:00 php-fpm35081: /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 192.168.255.238
2024-11-06T02:50:50.000-03:00 dpinger34691: exiting on signal 15
2024-11-06T02:50:50.000-03:00 dpinger35739: exiting on signal 15
2024-11-06T02:50:50.000-03:00 dpinger30356: send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% alarm_hold 10000ms dest_addr 8.8.4.4 bind_addr 192.168.255.234 identifier "NETGW "
2024-11-06T02:50:50.000-03:00 dpinger30810: send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% alarm_hold 10000ms dest_addr 8.8.8.8 bind_addr 192.168.255.237 identifier "OIGW "
2024-11-06T02:50:51.000-03:00 php-fpm1650: /rc.dyndns.update: MONITOR: NETGW is available now, adding to routing group OI_NET
2024-11-06T02:50:51.000-03:00 php-fpm1650: 8.8.4.4|192.168.255.234|NETGW|16.492ms|4.583ms|0.0%|online|none
2024-11-06T02:50:51.000-03:00 unbound41161: [41161:0] info: service stopped (unbound 1.22.0).
2024-11-06T02:50:51.000-03:00 unbound41161: [41161:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2024-11-06T02:50:51.000-03:00 unbound41161: [41161:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
2024-11-06T02:50:51.000-03:00 unbound41161: [41161:0] info: server stats for thread 1: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2024-11-06T02:50:51.000-03:00 unbound41161: [41161:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
2024-11-06T02:50:51.000-03:00 php-fpm1650: /rc.dyndns.update: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:50:51.000-03:00 php-fpm1650: /rc.dyndns.update: Dynamic Dns (): Current WAN IP could not be determined, skipping update process.
2024-11-06T02:50:51.000-03:00 php-fpm1650: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:50:52.000-03:00 php-fpm92252: /rc.dyndns.update: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:50:52.000-03:00 php-fpm1650: /rc.dyndns.update: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:50:52.000-03:00 php-fpm92252: /rc.dyndns.update: Dynamic DNS () There was an error trying to determine the public IP for interface - OI_NET (ix2 ).
2024-11-06T02:50:52.000-03:00 php-fpm1650: /rc.dyndns.update: Dynamic DNS () There was an error trying to determine the public IP for interface - OI_NET (ix2 ).
2024-11-06T02:50:52.000-03:00 php-fpm73962: /rc.dyndns.update: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:50:52.000-03:00 php-fpm73962: /rc.dyndns.update: Dynamic DNS () There was an error trying to determine the public IP for interface - OI_NET (ix2 ).
2024-11-06T02:50:52.000-03:00 php-fpm89428: /rc.newwanip: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:50:52.000-03:00 php-fpm89428: /rc.newwanip: Dynamic DNS () There was an error trying to determine the public IP for interface - OI_NET (ix2 ).
2024-11-06T02:50:52.000-03:00 unbound87325: [87325:0] notice: init module 0: validator
2024-11-06T02:50:52.000-03:00 unbound87325: [87325:0] notice: init module 1: iterator
2024-11-06T02:50:52.000-03:00 unbound87325: [87325:0] info: start of service (unbound 1.22.0).
2024-11-06T02:50:53.000-03:00 php-fpm30187: /rc.start_packages: Configuration Change: (system): pfBlockerNG: saving DNSBL changes
2024-11-06T02:50:53.000-03:00 check_reload_status658: Syncing firewall
2024-11-06T02:50:54.000-03:00 tail_pfb24580: [pfBlockerNG] Firewall Filter Service stopped
2024-11-06T02:50:54.000-03:00 php_pfb25108: [pfBlockerNG] filterlog daemon stopped
2024-11-06T02:50:54.000-03:00 tail_pfb27634: [pfBlockerNG] Firewall Filter Service started
2024-11-06T02:50:55.000-03:00 php_pfb27860: [pfBlockerNG] filterlog daemon started
2024-11-06T02:50:56.000-03:00 unbound87325: [87325:1] info: generate keytag query _ta-4f66. NULL IN
2024-11-06T02:50:57.000-03:00 php-fpm96740: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:50:58.000-03:00 php-fpm92252: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:50:59.000-03:00 php-fpm73962: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:00.000-03:00 kea-dhcp45682: WARN [kea-dhcp4.dhcpsrv.0xd90ada12000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled.
2024-11-06T02:51:00.000-03:00 kea-dhcp45682: WARN [kea-dhcp4.dhcp4.0xd90ada12000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first.
2024-11-06T02:51:00.000-03:00 kea-dhcp45682: ERROR [kea-dhcp4.dhcp4.0xd90ada12000] DHCP4_PARSER_COMMIT_FAIL parser failed to commit changes: cannot lock socket lockfile, /var/run/kea4-ctrl-socket.lock, : Resource temporarily unavailable
2024-11-06T02:51:00.000-03:00 kea-dhcp45682: ERROR [kea-dhcp4.dhcp4.0xd90ada12000] DHCP4_CONFIG_LOAD_FAIL configuration error using file: /usr/local/etc/kea/kea-dhcp4.conf, reason: cannot lock socket lockfile, /var/run/kea4-ctrl-socket.lock, : Resource temporarily unavailable
2024-11-06T02:51:00.000-03:00 kea-dhcp45682: ERROR [kea-dhcp4.dhcp4.0xd90ada12000] DHCP4_INIT_FAIL failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /var/run/kea4-ctrl-socket.lock, : Resource temporarily unavailable
2024-11-06T02:51:00.000-03:00 php-fpm89428: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:00.000-03:00 php-cgi94640: servicewatchdog_cron.php: Service Watchdog detected service nut stopped. Restarting nut (UPS monitoring daemon)
2024-11-06T02:51:00.000-03:00 upsmon28154: Startup successful
2024-11-06T02:51:00.000-03:00 kea-dhcp429687: WARN [kea-dhcp4.dhcpsrv.0x13b3a7412000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled.
2024-11-06T02:51:00.000-03:00 kea-dhcp429687: WARN [kea-dhcp4.dhcp4.0x13b3a7412000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first.
2024-11-06T02:51:00.000-03:00 kea-dhcp429687: ERROR [kea-dhcp4.dhcp4.0x13b3a7412000] DHCP4_PARSER_COMMIT_FAIL parser failed to commit changes: cannot lock socket lockfile, /var/run/kea4-ctrl-socket.lock, : Resource temporarily unavailable
2024-11-06T02:51:00.000-03:00 kea-dhcp429687: ERROR [kea-dhcp4.dhcp4.0x13b3a7412000] DHCP4_CONFIG_LOAD_FAIL configuration error using file: /usr/local/etc/kea/kea-dhcp4.conf, reason: cannot lock socket lockfile, /var/run/kea4-ctrl-socket.lock, : Resource temporarily unavailable
2024-11-06T02:51:00.000-03:00 kea-dhcp429687: ERROR [kea-dhcp4.dhcp4.0x13b3a7412000] DHCP4_INIT_FAIL failed to initialize Kea server: configuration error using file '/usr/local/etc/kea/kea-dhcp4.conf': cannot lock socket lockfile, /var/run/kea4-ctrl-socket.lock, : Resource temporarily unavailable
2024-11-06T02:51:01.000-03:00 php-fpm69280: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:02.000-03:00 php-fpm35081: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:02.000-03:00 php-fpm96740: /rc.dyndns.update: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:51:02.000-03:00 php-fpm96740: /rc.dyndns.update: Dynamic Dns (): Current WAN IP could not be determined, skipping update process.
2024-11-06T02:51:02.000-03:00 php-fpm96740: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:04.000-03:00 php-fpm69280: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:04.000-03:00 php-fpm96740: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:06.000-03:00 php-fpm96740: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:06.000-03:00 php-fpm92252: /rc.dyndns.update: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:51:06.000-03:00 php-fpm92252: /rc.dyndns.update: Dynamic Dns (): Current WAN IP could not be determined, skipping update process.
2024-11-06T02:51:06.000-03:00 php-fpm92252: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:06.000-03:00 php-fpm35081: /rc.newwanip: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:51:06.000-03:00 php-fpm35081: /rc.newwanip: Dynamic DNS () There was an error trying to determine the public IP for interface - OI_NET (ix2 ).
2024-11-06T02:51:06.000-03:00 php-fpm73962: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:07.000-03:00 php-fpm96740: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:08.000-03:00 php-fpm92252: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:08.000-03:00 php-fpm89428: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:09.000-03:00 php-fpm73962: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:10.000-03:00 php-fpm89428: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:10.000-03:00 php-fpm69280: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:11.000-03:00 php-fpm92252: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:11.000-03:00 php-fpm35081: /rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:11.000-03:00 php-fpm89428: /rc.newwanip: Resyncing OpenVPN instances for interface NET.
2024-11-06T02:51:11.000-03:00 php-fpm89428: /rc.newwanip: Creating rrd update script
2024-11-06T02:51:12.000-03:00 php-fpm96740: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
2024-11-06T02:51:13.000-03:00 php-fpm89428: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 192.168.255.234 -> 192.168.255.234 - Restarting packages.
2024-11-06T02:51:13.000-03:00 check_reload_status658: Starting packages
2024-11-06T02:51:13.000-03:00 check_reload_status658: Reloading filter
2024-11-06T02:51:13.000-03:00 check_reload_status658: Reloading filter
2024-11-06T02:51:14.000-03:00 php-fpm69280: /rc.newwanip: Dynamic DNS custom (): Public IP address could not be extracted from Check IP Service
2024-11-06T02:51:14.000-03:00 php-fpm69280: /rc.newwanip: Dynamic DNS () There was an error trying to determine the public IP for interface - OI_NET (ix2 ).
2024-11-06T02:51:14.000-03:00 php-fpm1650: /rc.start_packages: Restarting/Starting all packages.
2024-11-06T02:51:14.000-03:00 php-fpm1650: /rc.start_packages: Stopping service nut
2024-11-06T02:51:14.000-03:00 upsmon28704: Signal 15: exiting
2024-11-06T02:51:14.000-03:00 php-fpm1650: /rc.start_packages: Starting service nut
2024-11-06T02:51:14.000-03:00 upsmon31891: Startup successful
I'm using 24.11.b.20241031.0600 build on a SG-4100 device.
Packages installed:
acme
aws-wizard
ipsec-profile-wizard
Netgate_Firmware_Upgrade
nut (configured to reach a remote server, not using the USB port from the nobreak to the SG-4100)
pfBlockerNG-devel (only IP based feeds in use, DNSBL disabled)
Service_Watchdog (Only NUT added to the service_watchdog)
System_Patches
WireGuard
Related issues
Updated by Jim Pingle 15 days ago
- Tracker changed from Bug to Regression
- Project changed from pfSense Plus to pfSense
- Subject changed from KEA service is down and cannot be enabled after down event. to KEA service is down and cannot be enabled after down event
- Category changed from DHCP Server (IPv4) to DHCP (IPv4)
- Assignee set to Christian McDonald
- Target version set to 2.8.0
- Affected Plus Version deleted (
24.11) - Plus Target Version set to 24.11
Updated by Jim Pingle 15 days ago
The error here is the same as #14977 but that build should have the fix in it, unless something else is happening in this specific case.
Does the /var/run/kea4-ctrl-socket.lock
file actually still exist on your setup while Kea isn't running? If so, does removing that file allow it to start?
Updated by Marcelo Cury 15 days ago
The file exists.
[24.11-BETA][root@pfSense.home.arpa]/root: ls lah /var/run/kea4-ctrl-socket.lock 1 root wheel 0B Nov 6 02:50 /var/run/kea4-ctrl-socket.lock
-rw------
Just deleted that file with a simple rm /var/run/kea4-ctrl-socket.lock and the service started normally after, service is green again.
Updated by Christian McDonald 15 days ago
- Status changed from New to Duplicate
- Parent task set to #14977
Updated by Christian McDonald 15 days ago
- Subject changed from KEA service is down and cannot be enabled after down event to Kea service is down and cannot be enabled after down event
- Release Notes changed from Default to Force Exclusion
Updated by Jim Pingle 15 days ago
- Target version deleted (
2.8.0) - Parent task deleted (
#14977) - Plus Target Version deleted (
24.11)
Updated by Jim Pingle 15 days ago
- Is duplicate of Bug #14977: Kea fails to restart due to race between process termination and startup added