DHCP server suddenly off
-
My DHCP server suddenly stopped last night and everything that didn't have manual IP lost its network connection.
I was able to log in to the webinterface and start it again and everything is back to normal.
Can anyone help me figure out what happened and how I can avoid it happening again.
My router is:
Netgate 3100
Serial: 1101200004
Netgate Device ID: 2c**"" ""24.11-RELEASE (arm)
built on Sat Jan 11 17:11:00 CET 2025
FreeBSD 15.0-CURRENTLog from today looks like this
Sep 14 06:01:43 php 54545 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Sep 14 08:00:00 php 16219 [pfBlockerNG] Starting cron process. Sep 14 08:01:45 php 16219 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Sep 14 09:02:29 kernel pid 83107 (kea-dhcp4), jid 0, uid 0: exited on signal 11 (core dumped) Sep 14 10:00:00 php 48048 [pfBlockerNG] Starting cron process. Sep 14 10:01:42 php 48048 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Sep 14 11:03:48 php-fpm 63153 /index.php: webConfigurator authentication error for user 'admin' from: 192.168.100.1 Sep 14 11:03:48 sshguard 81810 Attack from "192.168.100.1" on service unknown service with danger 10. Sep 14 11:06:13 php-fpm 63153 /index.php: webConfigurator authentication error for user 'Admin' from: 192.168.100.1 Sep 14 11:06:13 sshguard 81810 Attack from "192.168.100.1" on service unknown service with danger 10. Sep 14 11:06:23 php-fpm 63153 /index.php: webConfigurator authentication error for user 'Admin' from: 192.168.100.1 Sep 14 11:06:23 sshguard 81810 Attack from "192.168.100.1" on service unknown service with danger 10. Sep 14 11:06:23 sshguard 81810 Blocking "192.168.100.1/32" for 120 secs (3 attacks in 155 secs, after 1 abuses over 155 secs.) Sep 14 11:07:33 nginx 2025/09/14 11:07:33 [crit] 33346#100098: *3270884 SSL_write() failed (13: Permission denied) while processing HTTP/2 connection, client: 192.168.100.1, server: 0.0.0.0:10443 Sep 14 11:09:01 sshguard 81810 192.168.100.1: unblocking after 158 secs Sep 14 11:09:02 nginx 2025/09/14 11:09:02 [error] 33060#100136: accept4() failed (53: Software caused connection abort) Sep 14 11:15:03 php-fpm 63153 /index.php: Successful login for user 'admin' from: 192.168.100.1 (Local Database) Sep 14 11:18:20 php-fpm 1393 /status_services.php: The command '/usr/local/etc/rc.d/haproxy.sh stop' returned exit code '1', the output was 'Stopping haproxy. Waiting for PIDS: 86485. Stopping haproxy. No matching processes were found' Sep 14 11:18:21 php-cgi 82704 haproxy: starting old pid:86485 Sep 14 11:18:22 php-cgi 82704 haproxy: started new pid:84480 Sep 14 12:00:00 php 30805 [pfBlockerNG] Starting cron process. Sep 14 12:01:46 php 30805 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Sep 14 12:30:00 php-cgi 14654 rc.update_urltables: /etc/rc.update_urltables: Starting up. Sep 14 12:30:00 php-cgi 14654 rc.update_urltables: /etc/rc.update_urltables: Sleeping for 31 seconds. Sep 14 12:30:31 php-cgi 14654 rc.update_urltables: /etc/rc.update_urltables: Starting URL table alias updates Sep 14 12:30:31 php-cgi 14654 rc.update_urltables: /etc/rc.update_urltables: pfB_PRI1_v4 does not need updating. Sep 14 12:30:31 php-cgi 14654 rc.update_urltables: /etc/rc.update_urltables: pfB_PRI2_v4 does not need updating. Sep 14 14:00:00 php 22071 [pfBlockerNG] Starting cron process. Sep 14 14:01:48 php 22071 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Sep 14 16:00:00 php 12993 [pfBlockerNG] Starting cron process. Sep 14 16:01:43 php 12993 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Sep 14 12:54:44 dhcp6c 43072 Sending Solicit Sep 14 12:56:36 dhcp6c 43072 Sending Solicit Sep 14 12:57:07 kea-dhcp4 72463 WARN [kea-dhcp4.dhcpsrv.0x2018c000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled. Sep 14 12:57:07 kea-dhcp4 72463 WARN [kea-dhcp4.dhcp4.0x2018c000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first. Sep 14 12:57:07 kea-dhcp4 72463 WARN [kea-dhcp4.dhcpsrv.0x2018c000] DHCPSRV_MULTIPLE_RAW_SOCKETS_PER_IFACE current configuration will result in opening multiple broadcast capable sockets on some interfaces and some DHCP messages may be duplicated Sep 14 12:57:07 kea-dhcp4 72463 WARN [kea-dhcp4.dhcp4.0x2018c000] DHCP4_MULTI_THREADING_INFO enabled: yes, number of threads: 2, queue size: 64 Sep 14 12:58:47 dhcp6c 43072 Sending Solicit Sep 14 13:00:54 dhcp6c 43072 Sending Solicit Sep 14 13:02:54 dhcp6c 43072 Sending Solicit Sep 14 13:04:46 dhclient 28738 DHCPREQUEST on mvneta2 to x.xxx.xxx.xxx port 67 Sep 14 13:04:46 dhclient 28738 DHCPACK from x.xxx.xxx.xxx Sep 14 13:04:46 dhclient 86956 RENEW Sep 14 13:04:46 dhclient 87846 Creating resolv.conf Sep 14 13:04:46 dhclient 28738 bound to xx.xx.xxx.xx -- renewal in 5400 seconds. Sep 14 13:04:56 dhcp6c 43072 Sending Solicit Sep 14 13:06:45 dhcp6c 43072 Sending Solicit
The attacks is me writing my login wrong trying to figure out what is going on.
If another log can help I'll post it ASAP.
Thank you. -
Normally, the system log would indicate why the DHCP server, at 12:57:07, was (re) restarted.
These are the normal "kea DHCPv4 startup" log lines :
..... WARN [kea-dhcp4.dhcpsrv.0xff507212000] DHCPSRV_MT_DISABLED_QUEUE_CONTROL disabling dhcp queue control when multi-threading is enabled. ..... WARN [kea-dhcp4.dhcp4.0xff507212000] DHCP4_RESERVATIONS_LOOKUP_FIRST_ENABLED Multi-threading is enabled and host reservations lookup is always performed first. ..... WARN [kea-dhcp4.dhcp4.0xff507212000] DHCP4_MULTI_THREADING_INFO enabled: yes, number of threads: 2, queue size: 64
You have an extra one :
WARN [kea-dhcp4.dhcpsrv.0x2018c000] DHCPSRV_MULTIPLE_RAW_SOCKETS_PER_IFACE current configuration will result in opening multiple broadcast capable sockets on some interfaces and some DHCP messages may be duplicated
I don't recall seeing that one.
Maybe because you use an old pfSense version, so you see old bugs ? ^^
I can really recommend the 25.07.1 pfSense it's rock solid. -
@Gertjan
Thank you, I look through the last 500 entries in the log and there was nothing but repeat entries, nothing about starting and stopping the dhcp server, only the one you see where I started it again.
Thank you for pointing out thisight be an old bug, I will update as soon as I can.