Frequent unbound restarts
-
@jasonarlouser Your excellent write-up helped me understand this issue -- thank you. I was seeing the same frequent restarts w/ dhcp computer names and long restart times due to pfBlockerNG.
I recently switched (back) to OpnSense, partly for this reason (and partly due to the widening community/pro version split), and have been happy to see that the OpnSense Unbound package now has rudimentary DNSBL baked-in. It doesn't sinkhole to a specific IP for stats-gathering like pfBlockerNG, but it certainly blocks well enough. That, plus zone reloads with unbound-control have (so far) led to a much better experience.
-
Sorry to hijack this topic but I want to make sure I'm having the same issue:
I have a pihole set as the primary DNS on the DHCP lease. Pihole sends all DNS requests to Pfsense on the same subnet.
Originaly I had pfsense set to forward to clouflare (1.1.1.1) but now I unchecked forwarder mode (see screenshot below)
The dns requests were much faster and website browsing feels faster (so that is positive). But the down side is that one or two times daily (usually in the midnight and when waking up in the morning we have no internet). This is purely a dns issue because I can browse to external IP's (for example 1.1.1.1).
When checking the logs I see:
dhcplog:
Mar 3 08:41:30 Porsche dhclient[15017]: connection closed Mar 3 08:41:30 Porsche dhclient[15017]: exiting. Mar 3 08:41:42 Porsche dhclient[53164]: Cannot open or create pidfile: No such file or directory Mar 3 08:41:49 Porsche dhclient[64571]: PREINIT Mar 3 08:41:49 Porsche dhclient[53164]: DHCPREQUEST on igb0 to 255.255.255.255 port 67 Mar 3 08:41:50 Porsche dhclient[53164]: DHCPREQUEST on igb0 to 255.255.255.255 port 67 Mar 3 08:41:52 Porsche dhclient[53164]: DHCPREQUEST on igb0 to 255.255.255.255 port 67 Mar 3 08:41:56 Porsche dhclient[53164]: DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 1 Mar 3 08:41:57 Porsche dhclient[53164]: DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 1 Mar 3 08:41:58 Porsche dhclient[53164]: DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 2 Mar 3 08:42:00 Porsche dhclient[53164]: DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 5 Mar 3 08:42:01 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.148 from 44:bb:3b:01:3f:86 via igb1.10 Mar 3 08:42:01 Porsche dhcpd[23031]: DHCPACK on 172.16.108.148 to 44:bb:3b:01:3f:86 via igb1.10 Mar 3 08:42:01 Porsche dhcpleases[3459]: Sending HUP signal to dns daemon(11064) Mar 3 08:42:01 Porsche dhcpleases[3459]: Could not deliver signal HUP to process 11064: No such process. Mar 3 08:42:05 Porsche dhclient[53164]: DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 12 Mar 3 08:42:05 Porsche dhclient[53164]: DHCPOFFER from 192.168.100.1 Mar 3 08:42:05 Porsche dhclient[65911]: ARPSEND Mar 3 08:42:07 Porsche dhclient[66097]: ARPCHECK Mar 3 08:42:07 Porsche dhclient[53164]: DHCPREQUEST on igb0 to 255.255.255.255 port 67 Mar 3 08:42:08 Porsche dhclient[53164]: DHCPACK from 192.168.100.1 Mar 3 08:42:08 Porsche dhclient[66684]: BOUND Mar 3 08:42:08 Porsche dhclient[67239]: Deleting old routes Mar 3 08:42:08 Porsche dhclient[68329]: Starting add_new_address() Mar 3 08:42:08 Porsche dhclient[68387]: ifconfig igb0 inet 192.168.100.10 netmask 255.255.255.0 broadcast 192.168.100.255 Mar 3 08:42:08 Porsche dhclient[68863]: New IP Address (igb0): 192.168.100.10 Mar 3 08:42:08 Porsche dhclient[68989]: New Subnet Mask (igb0): 255.255.255.0 Mar 3 08:42:08 Porsche dhclient[69220]: New Broadcast Address (igb0): 192.168.100.255 Mar 3 08:42:08 Porsche dhclient[69506]: New Routers (igb0): 192.168.100.1 Mar 3 08:42:08 Porsche dhclient[69813]: Adding new routes to interface: igb0 Mar 3 08:42:08 Porsche dhclient[71080]: /sbin/route add -host 192.168.100.1 -iface igb0 Mar 3 08:42:08 Porsche dhclient[71531]: /sbin/route add default 192.168.100.1 Mar 3 08:42:08 Porsche dhclient[71760]: Creating resolv.conf Mar 3 08:42:08 Porsche dhclient[53164]: bound to 192.168.100.10 -- renewal in 30 seconds. Mar 3 08:42:08 Porsche dhcpd[23031]: uid lease 192.168.2.245 for client 18:c0:4d:68:33:da is duplicate on 192.168.2.0/24 Mar 3 08:42:08 Porsche dhcpd[23031]: DHCPDISCOVER from 18:c0:4d:68:33:da via igb1 Mar 3 08:42:08 Porsche dhcpd[23031]: DHCPOFFER on 192.168.2.100 to 18:c0:4d:68:33:da via igb1 Mar 3 08:42:08 Porsche dhcpd[23031]: uid lease 192.168.2.245 for client 18:c0:4d:68:33:da is duplicate on 192.168.2.0/24 Mar 3 08:42:08 Porsche dhcpd[23031]: DHCPREQUEST for 192.168.2.100 (192.168.2.1) from 18:c0:4d:68:33:da via igb1 Mar 3 08:42:08 Porsche dhcpd[23031]: DHCPACK on 192.168.2.100 to 18:c0:4d:68:33:da via igb1 Mar 3 08:42:09 Porsche dhcpleases[81312]: Sending HUP signal to dns daemon(11064) Mar 3 08:42:09 Porsche dhcpleases[81312]: Could not deliver signal HUP to process 11064: No such process. Mar 3 08:42:09 Porsche dhcpleases[86520]: Sending HUP signal to dns daemon(11064) Mar 3 08:42:10 Porsche dhcpleases[86520]: Could not deliver signal HUP to process 11064: No such process. Mar 3 08:42:12 Porsche dhcpleases[97689]: Sending HUP signal to dns daemon(11064) Mar 3 08:42:12 Porsche dhcpleases[97689]: Could not deliver signal HUP to process 11064: No such process. Mar 3 08:42:19 Porsche dhcpd[23031]: uid lease 172.16.108.108 for client 02:0f:b5:78:8f:32 is duplicate on 172.16.108.0/24 Mar 3 08:42:19 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.65 from 02:0f:b5:78:8f:32 via igb1.10 Mar 3 08:42:19 Porsche dhcpd[23031]: DHCPACK on 172.16.108.65 to 02:0f:b5:78:8f:32 via igb1.10 Mar 3 08:42:38 Porsche dhclient[71955]: DHCPREQUEST on igb0 to 192.168.100.1 port 67 Mar 3 08:42:39 Porsche dhclient[71955]: DHCPACK from 192.168.100.1 Mar 3 08:42:39 Porsche dhclient[23088]: RENEW Mar 3 08:42:39 Porsche dhclient[23455]: Creating resolv.conf Mar 3 08:42:39 Porsche dhclient[71955]: bound to 192.168.100.10 -- renewal in 30 seconds. Mar 3 08:42:48 Porsche dhcpd[23031]: uid lease 172.16.108.116 for client 64:16:66:87:71:39 is duplicate on 172.16.108.0/24 Mar 3 08:42:48 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.69 from 64:16:66:87:71:39 via igb1.10 Mar 3 08:42:48 Porsche dhcpd[23031]: DHCPACK on 172.16.108.69 to 64:16:66:87:71:39 via igb1.10 Mar 3 08:42:52 Porsche dhcpd[23031]: DHCPRELEASE of 172.16.108.73 from 64:16:66:c0:7b:09 via igb1.10 (not found) Mar 3 08:43:03 Porsche dhcpd[91624]: Internet Systems Consortium DHCP Server 4.4.2 Mar 3 08:43:03 Porsche dhcpd[91624]: Copyright 2004-2020 Internet Systems Consortium. Mar 3 08:43:03 Porsche dhcpd[91624]: All rights reserved. Mar 3 08:43:03 Porsche dhcpd[91624]: For info, please visit https://www.isc.org/software/dhcp/ Mar 3 08:43:03 Porsche dhcpd[91624]: Config file: /etc/dhcpd.conf Mar 3 08:43:03 Porsche dhcpd[91624]: Internet Systems Consortium DHCP Server 4.4.2 Mar 3 08:43:03 Porsche dhcpd[91624]: Database file: /var/db/dhcpd.leases Mar 3 08:43:03 Porsche dhcpd[91624]: Copyright 2004-2020 Internet Systems Consortium. Mar 3 08:43:03 Porsche dhcpd[91624]: PID file: /var/run/dhcpd.pid Mar 3 08:43:03 Porsche dhcpd[91624]: All rights reserved. Mar 3 08:43:03 Porsche dhcpd[91624]: For info, please visit https://www.isc.org/software/dhcp/ Mar 3 08:43:03 Porsche dhcpd[91624]: Wrote 0 class decls to leases file. Mar 3 08:43:03 Porsche dhcpd[91624]: Wrote 0 deleted host decls to leases file. Mar 3 08:43:03 Porsche dhcpd[91624]: Wrote 0 new dynamic host decls to leases file. Mar 3 08:43:03 Porsche dhcpd[91624]: Wrote 120 leases to leases file. Mar 3 08:43:03 Porsche dhcpd[91624]: Listening on BPF/igb1.20/00:e0:67:21:30:bd/10.10.10.0/24 Mar 3 08:43:03 Porsche dhcpd[91624]: Sending on BPF/igb1.20/00:e0:67:21:30:bd/10.10.10.0/24 Mar 3 08:43:03 Porsche dhcpd[91624]: Listening on BPF/igb1.10/00:e0:67:21:30:bd/172.16.108.0/24 Mar 3 08:43:03 Porsche dhcpd[91624]: Sending on BPF/igb1.10/00:e0:67:21:30:bd/172.16.108.0/24 Mar 3 08:43:03 Porsche dhcpd[91624]: Listening on BPF/igb1/00:e0:67:21:30:bd/192.168.2.0/24 Mar 3 08:43:03 Porsche dhcpd[91624]: Sending on BPF/igb1/00:e0:67:21:30:bd/192.168.2.0/24 Mar 3 08:43:03 Porsche dhcpd[91624]: Sending on Socket/fallback/fallback-net Mar 3 08:43:03 Porsche dhcpd[91624]: Server starting service. Mar 3 08:43:03 Porsche dhcpleases[97689]: Sending HUP signal to dns daemon(81955) Mar 3 08:43:03 Porsche dhcpleases[97689]: Sending HUP signal to dns daemon(81955) Mar 3 08:43:04 Porsche dhclient[65006]: connection closed Mar 3 08:43:04 Porsche dhclient[65006]: exiting. Mar 3 08:43:58 Porsche dhclient[10769]: Cannot open or create pidfile: No such file or directory Mar 3 08:44:03 Porsche dhclient[13655]: PREINIT Mar 3 08:44:03 Porsche dhclient[14564]: EXPIRE Mar 3 08:44:03 Porsche dhclient[14980]: Deleting old routes Mar 3 08:44:03 Porsche dhclient[16065]: PREINIT Mar 3 08:44:03 Porsche dhclient[10769]: DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 2 Mar 3 08:44:03 Porsche dhclient[10769]: DHCPDISCOVER on igb0 to 255.255.255.255 port 67 interval 3 Mar 3 08:44:03 Porsche dhclient[10769]: DHCPOFFER from 212.142.39.9 Mar 3 08:44:03 Porsche dhclient[16922]: ARPSEND Mar 3 08:44:03 Porsche dhclient[10769]: DHCPOFFER from 212.142.39.9 Mar 3 08:44:03 Porsche dhclient[10769]: DHCPOFFER already seen. Mar 3 08:44:05 Porsche dhclient[17350]: ARPCHECK Mar 3 08:44:05 Porsche dhclient[10769]: DHCPREQUEST on igb0 to 255.255.255.255 port 67 Mar 3 08:44:05 Porsche dhclient[10769]: DHCPACK from 212.142.39.9 Mar 3 08:44:05 Porsche dhclient[18240]: BOUND Mar 3 08:44:05 Porsche dhclient[18973]: Deleting old routes Mar 3 08:44:05 Porsche dhclient[19356]: Starting add_new_address() Mar 3 08:44:05 Porsche dhclient[19543]: ifconfig igb0 inet 77.xx.xx.xx netmask 255.255.255.0 broadcast 255.255.255.255 Mar 3 08:44:05 Porsche dhclient[19739]: New IP Address (igb0): 77.xx.xx.xx Mar 3 08:44:05 Porsche dhclient[20040]: New Subnet Mask (igb0): 255.255.255.0 Mar 3 08:44:05 Porsche dhclient[20169]: New Broadcast Address (igb0): 255.255.255.255 Mar 3 08:44:05 Porsche dhclient[20498]: New Routers (igb0): 77.xx.xx.1 Mar 3 08:44:05 Porsche dhclient[20648]: Adding new routes to interface: igb0 Mar 3 08:44:05 Porsche dhclient[20963]: Creating resolv.conf Mar 3 08:44:05 Porsche dhclient[10769]: bound to 77.xx.xx.xx -- renewal in 78309 seconds. Mar 3 08:44:07 Porsche dhcpleases[49551]: Sending HUP signal to dns daemon(48351) Mar 3 08:44:09 Porsche dhcpd[60926]: Internet Systems Consortium DHCP Server 4.4.2 Mar 3 08:44:09 Porsche dhcpd[60926]: Copyright 2004-2020 Internet Systems Consortium. Mar 3 08:44:09 Porsche dhcpd[60926]: All rights reserved. Mar 3 08:44:09 Porsche dhcpd[60926]: For info, please visit https://www.isc.org/software/dhcp/ Mar 3 08:44:09 Porsche dhcpd[60926]: Config file: /etc/dhcpd.conf Mar 3 08:44:09 Porsche dhcpd[60926]: Database file: /var/db/dhcpd.leases Mar 3 08:44:09 Porsche dhcpd[60926]: PID file: /var/run/dhcpd.pid Mar 3 08:44:09 Porsche dhcpd[60926]: Internet Systems Consortium DHCP Server 4.4.2 Mar 3 08:44:09 Porsche dhcpd[60926]: Copyright 2004-2020 Internet Systems Consortium. Mar 3 08:44:09 Porsche dhcpd[60926]: All rights reserved. Mar 3 08:44:09 Porsche dhcpd[60926]: For info, please visit https://www.isc.org/software/dhcp/ Mar 3 08:44:09 Porsche dhcpd[60926]: Wrote 0 class decls to leases file. Mar 3 08:44:09 Porsche dhcpd[60926]: Wrote 0 deleted host decls to leases file. Mar 3 08:44:09 Porsche dhcpd[60926]: Wrote 0 new dynamic host decls to leases file. Mar 3 08:44:09 Porsche dhcpd[60926]: Wrote 120 leases to leases file. Mar 3 08:44:09 Porsche dhcpd[60926]: Listening on BPF/igb1.20/00:e0:67:21:30:bd/10.10.10.0/24 Mar 3 08:44:09 Porsche dhcpd[60926]: Sending on BPF/igb1.20/00:e0:67:21:30:bd/10.10.10.0/24 Mar 3 08:44:09 Porsche dhcpd[60926]: Listening on BPF/igb1.10/00:e0:67:21:30:bd/172.16.108.0/24 Mar 3 08:44:09 Porsche dhcpd[60926]: Sending on BPF/igb1.10/00:e0:67:21:30:bd/172.16.108.0/24 Mar 3 08:44:09 Porsche dhcpd[60926]: Listening on BPF/igb1/00:e0:67:21:30:bd/192.168.2.0/24 Mar 3 08:44:09 Porsche dhcpd[60926]: Sending on BPF/igb1/00:e0:67:21:30:bd/192.168.2.0/24 Mar 3 08:44:09 Porsche dhcpd[60926]: Sending on Socket/fallback/fallback-net Mar 3 08:44:09 Porsche dhcpd[60926]: Server starting service. Mar 3 08:44:09 Porsche dhcpleases[49551]: Sending HUP signal to dns daemon(48351) Mar 3 08:44:09 Porsche dhcpleases[49551]: Sending HUP signal to dns daemon(48351) Mar 3 08:44:15 Porsche dhcpd[60926]: reuse_lease: lease age 134 (secs) under 25% threshold, reply with unaltered, existing lease for 172.16.108.148 Mar 3 08:44:15 Porsche dhcpd[60926]: DHCPDISCOVER from 44:bb:3b:01:3f:86 via igb1.10 Mar 3 08:44:15 Porsche dhcpd[60926]: DHCPOFFER on 172.16.108.148 to 44:bb:3b:01:3f:86 via igb1.10 Mar 3 08:44:15 Porsche dhcpd[60926]: reuse_lease: lease age 134 (secs) under 25% threshold, reply with unaltered, existing lease for 172.16.108.148 Mar 3 08:44:15 Porsche dhcpd[60926]: DHCPREQUEST for 172.16.108.148 (172.16.108.1) from 44:bb:3b:01:3f:86 via igb1.10 Mar 3 08:44:15 Porsche dhcpd[60926]: DHCPACK on 172.16.108.148 to 44:bb:3b:01:3f:86 via igb1.10 Mar 3 08:44:16 Porsche dhcpd[60926]: reuse_lease: lease age 600 (secs) under 25% threshold, reply with unaltered, existing lease for 172.16.108.144 Mar 3 08:44:16 Porsche dhcpd[60926]: DHCPDISCOVER from 44:bb:3b:00:c3:d5 via igb1.10 Mar 3 08:44:16 Porsche dhcpd[60926]: DHCPOFFER on 172.16.108.144 to 44:bb:3b:00:c3:d5 via igb1.10 Mar 3 08:44:16 Porsche dhcpd[60926]: reuse_lease: lease age 600 (secs) under 25% threshold, reply with unaltered, existing lease for 172.16.108.144 Mar 3 08:44:16 Porsche dhcpd[60926]: DHCPREQUEST for 172.16.108.144 (172.16.108.1) from 44:bb:3b:00:c3:d5 via igb1.10
resolver
Mar 3 08:43:02 Porsche unbound[81955]: [81955:0] notice: init module 0: validator Mar 3 08:43:02 Porsche unbound[81955]: [81955:0] notice: init module 1: iterator Mar 3 08:43:02 Porsche unbound[81955]: [81955:0] info: start of service (unbound 1.13.0). Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: service stopped (unbound 1.13.0). Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 0: 3 queries, 0 answers from cache, 3 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 0: requestlist max 3 avg 1.66667 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 1: 8 queries, 0 answers from cache, 8 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 1: requestlist max 7 avg 3.75 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 2: 4 queries, 0 answers from cache, 4 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 2: requestlist max 4 avg 2.25 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 3: 7 queries, 0 answers from cache, 7 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 3: requestlist max 6 avg 3.28571 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] notice: Restart of unbound 1.13.0. Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] notice: init module 0: validator Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] notice: init module 1: iterator Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: start of service (unbound 1.13.0). Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: service stopped (unbound 1.13.0). Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] notice: Restart of unbound 1.13.0. Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] notice: init module 0: validator Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] notice: init module 1: iterator Mar 3 08:43:03 Porsche unbound[81955]: [81955:0] info: start of service (unbound 1.13.0). Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] notice: init module 0: validator Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] notice: init module 1: iterator Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: start of service (unbound 1.13.0). Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: service stopped (unbound 1.13.0). Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 0: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 1: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] notice: Restart of unbound 1.13.0. Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] notice: init module 0: validator Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] notice: init module 1: iterator Mar 3 08:44:07 Porsche unbound[48351]: [48351:0] info: start of service (unbound 1.13.0). Mar 3 08:44:08 Porsche unbound[48351]: [48351:3] info: generate keytag query _ta-4f66. NULL IN Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: service stopped (unbound 1.13.0). Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 1: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: average recursion processing time 0.364789 sec Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: histogram of recursion processing times Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: [25%]=0 median[50%]=0 [75%]=0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: lower(secs) upper(secs) recursions Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: 0.262144 0.524288 1 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 3: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: average recursion processing time 0.074963 sec Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: histogram of recursion processing times Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: [25%]=0 median[50%]=0 [75%]=0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: lower(secs) upper(secs) recursions Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: 0.065536 0.131072 1 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] notice: Restart of unbound 1.13.0. Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] notice: init module 0: validator Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] notice: init module 1: iterator Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: start of service (unbound 1.13.0). Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: service stopped (unbound 1.13.0). Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0 Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] notice: Restart of unbound 1.13.0. Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] notice: init module 0: validator Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] notice: init module 1: iterator Mar 3 08:44:09 Porsche unbound[48351]: [48351:0] info: start of service (unbound 1.13.0). Mar 3 08:44:10 Porsche unbound[48351]: [48351:2] info: generate keytag query _ta-4f66. NULL IN Mar 4 07:21:03 Porsche unbound[50999]: [50999:0] notice: init module 0: validator Mar 4 07:21:03 Porsche unbound[50999]: [50999:0] notice: init module 1: iterator Mar 4 07:21:03 Porsche unbound[50999]: [50999:0] info: start of service (unbound 1.13.0). Mar 4 07:21:04 Porsche unbound[50999]: [50999:1] info: generate keytag query _ta-4f66. NULL IN Mar 4 07:21:04 Porsche unbound[50999]: [50999:0] info: service stopped (unbound 1.13.0).
Is disabling the Register DHCP leases in the DNS Resolver sufficient to solve this problem and I am running into the same issue? Or should I change the code as mentioned above?
I also see duplicate DHCP lease errors (I think this might be related to the restarts?)
Mar 2 22:59:55 Porsche dhcpleases[3459]: Sending HUP signal to dns daemon(11064) Mar 2 23:01:20 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.76 from 44:07:0b:b7:a5:59 via igb1.10 Mar 2 23:01:20 Porsche dhcpd[23031]: DHCPACK on 172.16.108.76 to 44:07:0b:b7:a5:59 via igb1.10 Mar 2 23:04:39 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.139 from e2:81:d8:e1:a6:32 (iPhoneJ) via igb1.10 Mar 2 23:04:39 Porsche dhcpd[23031]: DHCPACK on 172.16.108.139 to e2:81:d8:e1:a6:32 (iPhoneJ) via igb1.10 Mar 2 23:04:39 Porsche dhcpleases[3459]: Sending HUP signal to dns daemon(11064) Mar 2 23:05:11 Porsche dhcpd[23031]: uid lease 192.168.2.167 for client 00:04:4b:5b:d4:60 is duplicate on 192.168.2.0/24 Mar 2 23:05:11 Porsche dhcpd[23031]: DHCPREQUEST for 192.168.2.131 from 00:04:4b:5b:d4:60 via igb1 Mar 2 23:05:11 Porsche dhcpd[23031]: DHCPACK on 192.168.2.131 to 00:04:4b:5b:d4:60 via igb1 Mar 2 23:05:28 Porsche dhcpd[23031]: DHCPREQUEST for 10.10.10.54 from e0:63:da:ca:b5:65 via igb1.20 Mar 2 23:05:28 Porsche dhcpd[23031]: DHCPACK on 10.10.10.54 to e0:63:da:ca:b5:65 (WoonkamerAP) via igb1.20 Mar 2 23:05:28 Porsche dhcpleases[3459]: Sending HUP signal to dns daemon(11064) Mar 2 23:08:26 Porsche dhcpd[23031]: uid lease 172.16.108.125 for client 18:56:80:1a:27:a0 is duplicate on 172.16.108.0/24 Mar 2 23:08:26 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.83 from 18:56:80:1a:27:a0 via igb1.10 Mar 2 23:08:26 Porsche dhcpd[23031]: DHCPACK on 172.16.108.83 to 18:56:80:1a:27:a0 via igb1.10 Mar 2 23:14:27 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.71 from b0:95:75:22:af:a1 via igb1.10 Mar 2 23:14:27 Porsche dhcpd[23031]: DHCPACK on 172.16.108.71 to b0:95:75:22:af:a1 via igb1.10 Mar 2 23:18:48 Porsche dhcpd[23031]: uid lease 192.168.2.150 for client e0:63:da:5d:8d:27 is duplicate on 192.168.2.0/24 Mar 2 23:18:48 Porsche dhcpd[23031]: DHCPREQUEST for 192.168.2.10 from e0:63:da:5d:8d:27 via igb1 Mar 2 23:18:48 Porsche dhcpd[23031]: DHCPACK on 192.168.2.10 to e0:63:da:5d:8d:27 via igb1 Mar 2 23:22:27 Porsche dhcpd[23031]: uid lease 192.168.2.164 for client e0:63:da:ca:b4:e1 is duplicate on 192.168.2.0/24 Mar 2 23:22:27 Porsche dhcpd[23031]: DHCPREQUEST for 192.168.2.13 from e0:63:da:ca:b4:e1 via igb1 Mar 2 23:22:27 Porsche dhcpd[23031]: DHCPACK on 192.168.2.13 to e0:63:da:ca:b4:e1 via igb1 Mar 2 23:22:34 Porsche dhcpd[23031]: uid lease 192.168.2.218 for client e0:63:da:ca:c2:c5 is duplicate on 192.168.2.0/24 Mar 2 23:22:34 Porsche dhcpd[23031]: DHCPREQUEST for 192.168.2.12 from e0:63:da:ca:c2:c5 via igb1 Mar 2 23:22:34 Porsche dhcpd[23031]: DHCPACK on 192.168.2.12 to e0:63:da:ca:c2:c5 via igb1 Mar 2 23:22:34 Porsche dhcpleases[3459]: Sending HUP signal to dns daemon(11064) Mar 2 23:22:57 Porsche dhcpd[23031]: DHCPREQUEST for 10.10.10.16 from e0:63:da:ca:b4:e1 via igb1.20 Mar 2 23:22:57 Porsche dhcpd[23031]: DHCPACK on 10.10.10.16 to e0:63:da:ca:b4:e1 via igb1.20 Mar 2 23:22:58 Porsche dhcpd[23031]: DHCPREQUEST for 10.10.10.51 from e0:63:da:ca:c2:c5 via igb1.20 Mar 2 23:22:58 Porsche dhcpd[23031]: DHCPACK on 10.10.10.51 to e0:63:da:ca:c2:c5 (SlaapkamerAP) via igb1.20 Mar 2 23:22:58 Porsche dhcpleases[3459]: Sending HUP signal to dns daemon(11064) Mar 2 23:22:59 Porsche dhcpd[23031]: uid lease 192.168.2.231 for client 74:ac:b9:1a:18:79 is duplicate on 192.168.2.0/24 Mar 2 23:22:59 Porsche dhcpd[23031]: DHCPREQUEST for 192.168.2.14 from 74:ac:b9:1a:18:79 via igb1 Mar 2 23:22:59 Porsche dhcpd[23031]: DHCPACK on 192.168.2.14 to 74:ac:b9:1a:18:79 via igb1 Mar 2 23:23:34 Porsche dhcpd[23031]: uid lease 172.16.108.108 for client 02:0f:b5:78:8f:32 is duplicate on 172.16.108.0/24 Mar 2 23:23:34 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.65 from 02:0f:b5:78:8f:32 via igb1.10 Mar 2 23:23:34 Porsche dhcpd[23031]: DHCPACK on 172.16.108.65 to 02:0f:b5:78:8f:32 via igb1.10 Mar 2 23:23:38 Porsche dhcpd[23031]: uid lease 172.16.108.121 for client 00:09:b0:e0:ed:47 is duplicate on 172.16.108.0/24 Mar 2 23:23:38 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.81 from 00:09:b0:e0:ed:47 via igb1.10
-
What pfSense version ?
@audiaddict said in Frequent unbound restarts:
Mar 3 08:42:01 Porsche dhcpd[23031]: DHCPREQUEST for 172.16.108.148 from 44:bb:3b:01:3f:86 via igb1.10
Mar 3 08:42:01 Porsche dhcpd[23031]: DHCPACK on 172.16.108.148 to 44:bb:3b:01:3f:86 via igb1.10
Mar 3 08:42:01 Porsche dhcpleases[3459]: Sending HUP signal to dns daemon(11064)With 2.4.5-p1, when this one is checked :
then, as mentioned, the IP and host name are registered into the DNS.
To do that, the resolver, unbound, has be to restarted.Consider using static MAC DHCP leases - and make the lease time as big as possible.
Or disable those option.@audiaddict said in Frequent unbound restarts:
Mar 3 08:42:08 Porsche dhclient[53164]: bound to 192.168.100.10 -- renewal in 30 seconds.
This is on the other side : WAN : Your DHCP client - remember : it asks a IP from an upstream (ISP ? ) router really lasts 1 minute or 60 seconds ?
Why ?? -
Version 2.5.0-RELEASE (amd64)
built on Tue Feb 16 08:56:29 EST 2021
FreeBSD 12.2-STABLENo idea on the WAN refresh.. this is a Ziggo (vodafone) ISP modem that I have no control over really. It's set to bridge.
Can you confirm by disabling the registering of DNS entries under DNS resolver - this should not cause these DNSresolver restarts?
Also any idea's why I'm getting double DHCP duplicates? See last logs.
I'm using static DHCP entries with mac address under DHCP server.
-
@audiaddict said in Frequent unbound restarts:
this is a Ziggo (vodafone) ISP modem that I have no control over really. It's set to bridge.
Then you would be sending them some words like
Geachte support, Is het mogelijk om de lease van iet wat meer dan 60 seconden te krijgen ?
@audiaddict said in Frequent unbound restarts:
Can you confirm by disabling the registering of DNS entries under DNS resolver - this should not cause these DNSresolver restarts?
After answering the same question, some 1000+ forum messages, from the last 2 years or so.
Yes, I can confirm.
This was the issue with 2.4.5-p1.How 2.5.0 works these days : dono.
I can see it's still HUPped. Maybe its not restarting anymore, but just re reading the config files, and among them, the modified /etc/hosts file that contains (updated) DHCP client IP hostname information.Cn you imagine what happens if you had a client device that was asking for a new lease every 30 seconds ??
It would totally explode unbound ..... as ir would have to handle the HUP alll the time.Believe me :
Make static DHCP MAC leases for your devices that need a fixed IP - host name relation.
Un check the option.
Done.I have de activated that option several years ago.
unbound is rock solid.edit :
Mar 3 08:43:58 Porsche dhclient[10769]: Cannot open or create pidfile: No such file or directory
isn't good.
-
@gertjan But the issue is this is mis-implemented. No HUP needs to be sent here and if so all that needs to happen is use the command specified above to reload the local zone (the only one which could possibly be affected by DHCP leases). I can't think of a single other product anywhere that has this problem because every other vendor knows how to deal with DHCP leases adding DNS names.
-
@jasonarlouser said in Frequent unbound restarts:
No HUP needs to be sent here and if so ....
Please check the "vendors" instruction : the ones who make and maintain unbound.
The question is : when is the local /etc/hosts file re read in ?
Or, you might bask : is there another way to communicate a running unbound process the presence of a new local host + IP ? (answer : yes, there is ..... )Back, in the dark ages, the manual was : look up in the C source code why HUP was needed, and what it does when one is received, etc.
It's time I make this tour again, see how the more recent unbound version behave.
But I'm registering unknown device's DHCP leases any more in my DNS. All the devices I need to contact have chosen host names, and chosen IP's addresses.
Same thing for IPv6.
So, it became a non issue for me.Anyway, the unbound+DHCP leases thing is an ongoing discussion for a couple of years now.
In the past of pfSense :
dnsmasq was used before, but considered to light - and has no DNSSEC support.
So, unbound came up ... and was choosen.
"bind" might be used, but was often left out as to - far to - big. -
This post is deleted! -
@brad-edmondson said in Frequent unbound restarts:
@lutel Still broken as you can see.
It is actually working in OpnSense, which was previously a pfSense fork but now refactored and based on HardenedBSD rather than FreeBSD.
This aged well.
-
@jwt Sorry, I don't follow.
Are you referencing the wireguard fiasco? Or was there some other news that put this into an updated context? An unbound regression in OpnSense 21.1.5?
On WireGuard, AFAIK OpnSense has a userspace daemon similar to what pfSense has offered for a while, not the in-kernel implementation that was apparently borked and then yanked.
EDIT:
Are you referring to this OpnSense forum post? I think that's isolated as that user had other problems when upgrading w/ unsupported packages (not to say unbound is unsupported, just that theirs seems like a complicated configuration).To be fair I did suffer from some constant unbound restarts on my own OpnSense box yesterday, but I haven't updated that machine from 21.1.4 to 21.1.5 yet so I'm 99% sure that was down to my toggling the ramdisk option for /var and losing unbound data at reboot. (I had read the option as /var/log ramdisk, which I assumed would have no ill effects. The /var option not so much since it encompasses so much more.)
-
Is there any news on this?
-
@sotirone still broken.
-
... or, if you have a couple of minutes :
Create Static DHCP MAC leases for every device you need to know by name and IPv4.
When done; do the magic click in the Unbound resolver settings page, then Save & Apply, and you just unbroke the issue. -
- https://redmine.pfsense.org/issues/5413 (unfixed in 2.6.0)
- https://redmine.pfsense.org/issues/12613 (unfixed in 2.6.0, unless you apply the patch manually)
- https://redmine.pfsense.org/issues/12612 (unfixed in 2.6.0, unless you apply the patch manually)
Both patches are half-assed workarounds. Sorry for the harsh words, but it is what it is.
-
I didn't say the issue(s) do not exist.
I highlighted a workaround. And no need to undo it when things get sorted out.Btw : when IPv6 takes over, static MAC DHCP becomes even more important.
Issue 12613 : wasn't aware of this one. My main switches, as pfSense, are fed by an UPS. And no one is ripping out cables here.
Issue 12612 : my pfSense uses DHCP on it's WAN interface. But guess what ?! I gave it a static DHCP MAC lease, set up in the OSP router"s settings.
Anyway, both 12613 and 12612 have a click solution now ;) -
@gertjan
rc.newwanip
events also happen when you power cycle devices connected directly to a LAN interface:/rc.newwanip: rc.newwanip: on (IP address: 192.168.120.30) (interface: LAN[lan]) (real interface: igb1).
Anyway, both 12613 and 12612 have a click solution now ;)
Yes, one that force restarts Unbound, which is the topic of this thread. ;)
-
Not the topic, I know, but :
@thiasaef said in Frequent unbound restarts:
/rc.newwanip: rc.newwanip: on (IP address: 192.168.120.30) (interface: LAN[lan]) (real interface: igb1).
A rc.newWANip IP event on a LAN interface ?
The WAN is called LAN here ?
ok ....
Something else ?The the WAN or whatever LAN/OPT/... NIC receives a LINK DOW / LINK UP event, the attached processes have to restart to take into account the new system configuration. That's somewhat logic, right ? And badly enough, that's how unbound is works.
As said earlier, maybe I'm just lucky here, as all implied devices, ISP router, pfSense, switches, are using an UPS so power isn't an issue. So no "LINK DOW / LINK UP" for me. -
@gertjan the name of the event is simply misleading. Read https://redmine.pfsense.org/issues/12612 carefully and you will see that I am correct.
the attached processes have to restart
Only if you do not implement it properly. Unbound did not need to be restarted on 2.4.5-p1 with the exact same configuration and it also does not need to be restarted in such a case if you install it on Linux and apply the same configuration there.
So no "LINK DOW / LINK UP" for me.
It's fine that you don't care about the bug, but trying to convince me that link downs on the LAN side are something that shouldn't happen is going nowhere.
-
@thiasaef I do care. But I'm human, so I care probably a bit more about issues that impact my own installation.
The question exists on the https://www.nlnetlabs.nl support forum to implement the hardware event directly in the unbound process, like bind (named) : no more restarts, interfaces that come and go are dynamically are updated by the the process** itself. Netgate can't (or won't) rewrite unbound for that. And they really can't replace unbound for bind as then they would have to 'support' the entire thing (bind=huge as it is also a domain name server etc)
** if this is even possible. FreeBSD is used here, and known to be pretty secure. Hardware network events can an impact on the system configuration and is thus security related.
If would be a big deal if a WAN interface get attached as a LAN type.
So, the final decision is pushed out of the kernel, to the 'user' - the admin. The admin can decide to keep the interfaces up == no more events.
This is me thinking out loud.Btw : I'm like you : just another pfSense user.
Anyway : the subject is "Frequent unbound restarts ".
Issue 12613 has a patch.
Issue 12612 has a patch.
Issue 5413 is ongoing, so I dealt with it 'my way'.
The first post from myself about this "5413" issue are dating from 2016 (?), when Netgate/pfSense switched from DNSmasq to unbound. All my networks are small - 50 devices @max that I have to know by name and IP, so I "Static MACced" them all, and disable DHCP Registration.
The latest pfBlocker-devel release also call for this measure :and I repeat : disabling this option will stop unbound from being restarted because of DHCP LAN events.
Some solutions have been proposed here : https://redmine.pfsense.org/issues/5413 but, IMHO, one is missing : a python 'DHCP-leases' scripts that reads the DHCP leases file. And also checks the time stamp of the DHCP-leases file, and read it again if a lease was added, disappeared, or got changed. Even with several thousands of DHCP leases, this file will not grow indefinitely (the number of leases is always a known max range).
This python script should also rewrite the /etc/hosts file - as unbound reads it upon restart.I know it would work, as the entire DNSBL is now based on a python script unbound extension.
It would be a great if some one could find a better solution as what is currently in place :
https://github.com/pfsense/FreeBSD-ports/blob/devel/sysutils/dhcpleases/files/dhcpleases.c line 604 : kill (HUP) unbound upon a DHCP server event.
I'm a (former) 'c' man myself, I can read Python but don't feel up to even experiment with it.
-
Netgate can't (or won't) rewrite unbound for that.
I agree and I would not whine about it if a) 2.4.5-p1 was suffering from the same issue (which it did not) or if b) it would not work on Linux either (which it does).
I'm a (former) 'c' man myself
Me too, which is why I can smell half-assed bug fixes from miles away.