Frequent unbound restarts

brad.edmondson · Mar 3, 2021, 5:34 AM

@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.

Gertjan · Mar 3, 2021, 7:06 AM

@brad-edmondson

I could present my :

login-to-view

Unbound just restart again.

Or was it because I just upgraded, at 07h00 am, the package pfBlockerNG-devel to the latest ...14 ?

Something I do nearly every day as fine polishing is happening after pfSense 2.5.0 came out.

If not, I guess my 'unbound' restarts .... one or twice a week, or less.
unbound restarts can be explained. Up to you to chose if it should happen. This forum is filled up with the why/when/what/what else.

So, we have the same code ... what differs is the set up (the admin).
Should I details mine ?

jasonArloUser · Mar 3, 2021, 7:39 AM

@lutel I detailed how to fix it more than a year ago. The IPv6 story also hasn't been addressed for years. I think it's time to accept that this product is dying and move onto products that are still being actively improved.

brad.edmondson · Mar 4, 2021, 12:48 AM

@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.

AudiAddict · Mar 4, 2021, 9:02 AM

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

Gertjan · Mar 4, 2021, 9:12 AM

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 :

login-to-view

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 ??

AudiAddict · Mar 4, 2021, 9:24 AM

@gertjan

Version 2.5.0-RELEASE (amd64)
built on Tue Feb 16 08:56:29 EST 2021
FreeBSD 12.2-STABLE

No 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.

Gertjan · Mar 4, 2021, 9:28 AM

@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.

jasonArloUser · Mar 4, 2021, 3:22 PM

@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.

Gertjan · Mar 4, 2021, 3:22 PM

@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.

jwt · Apr 23, 2021, 4:16 AM

This post is deleted!

jwt · Apr 23, 2021, 4:18 AM

@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.

brad.edmondson · Apr 23, 2021, 3:10 PM

@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.)

sotirone · Mar 16, 2022, 8:55 PM

Is there any news on this?

thiasaef · Mar 17, 2022, 2:59 PM

@sotirone still broken.

Gertjan · Mar 17, 2022, 1:12 PM

... 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.

thiasaef · Mar 17, 2022, 1:12 PM

@gertjan

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.

Gertjan · Mar 17, 2022, 1:48 PM

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 ;)

thiasaef · Mar 17, 2022, 1:54 PM

@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. ;)

Gertjan · Mar 17, 2022, 2:06 PM

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.