Unbound stop/start after enabling split DNS
-
@cabledude Do you have "Register DHCP leases in the DNS Resolver" checked? That will restart unbound at every lease renewal and is usually the cause of frequent restarts.
-
@steveits Hi Steve, no I haven't checked that option or any other options in DNS resolver. Apart from having pfBlockerNG-devel v3.1.0 installed and now the Split DNS the DNS resolver is at default settings.
Is it common to see the DNS resolver stop/start, given the default config? Here is a complete log filtered on "service". As you can see the stop/start events go back even to October 2021, when I did not have any Split DNS settings active.
There is probably a lot of pfBlocker cron updates in this log, but not every hour and not even every day.
Q2 Can there be any relation to RA OpenVPN logon events?
Thanks,
Pete[Edit sorry when I add the log I get the "post is flagged as spam by Akismet.com" notification ]
Pasted 50 lines now:
ec 8 04:51:57 unbound 28330 [28330:0] info: service stopped (unbound 1.12.0). Dec 8 04:52:03 unbound 10086 [10086:0] info: start of service (unbound 1.12.0). Dec 8 04:52:15 unbound 10086 [10086:0] info: service stopped (unbound 1.12.0). Dec 8 04:52:22 unbound 57268 [57268:0] info: start of service (unbound 1.12.0). Dec 8 04:52:28 unbound 57268 [57268:0] info: service stopped (unbound 1.12.0). Dec 8 04:52:34 unbound 27591 [27591:0] info: start of service (unbound 1.12.0). Dec 8 04:54:03 unbound 27591 [27591:0] info: service stopped (unbound 1.12.0). Dec 8 04:54:10 unbound 31317 [31317:0] info: start of service (unbound 1.12.0). Dec 11 00:01:42 unbound 31317 [31317:0] info: service stopped (unbound 1.12.0). Dec 11 00:01:47 unbound 54079 [54079:0] info: start of service (unbound 1.12.0). Dec 13 00:01:09 unbound 54079 [54079:0] info: service stopped (unbound 1.12.0). Dec 13 00:01:14 unbound 59513 [59513:0] info: start of service (unbound 1.12.0). Dec 15 00:01:07 unbound 59513 [59513:0] info: service stopped (unbound 1.12.0). Dec 15 00:01:12 unbound 25892 [25892:0] info: start of service (unbound 1.12.0). Dec 17 12:19:55 unbound 25892 [25892:0] info: service stopped (unbound 1.12.0). Dec 17 12:19:56 unbound 41410 [41410:0] info: start of service (unbound 1.12.0). Dec 17 12:20:57 unbound 41410 [41410:0] info: service stopped (unbound 1.12.0). Dec 17 12:20:58 unbound 28675 [28675:0] info: start of service (unbound 1.12.0). Dec 17 13:00:50 unbound 28675 [28675:0] info: service stopped (unbound 1.12.0). Dec 17 13:00:55 unbound 6089 [6089:0] info: start of service (unbound 1.12.0). Dec 18 00:01:11 unbound 6089 [6089:0] info: service stopped (unbound 1.12.0). Dec 18 00:01:16 unbound 21885 [21885:0] info: start of service (unbound 1.12.0). Dec 20 23:30:36 unbound 21885 [21885:0] info: service stopped (unbound 1.12.0). Dec 20 23:30:43 unbound 44290 [44290:0] info: start of service (unbound 1.12.0). Dec 20 23:52:57 unbound 44290 [44290:0] info: service stopped (unbound 1.12.0). Dec 20 23:53:03 unbound 43483 [43483:0] info: start of service (unbound 1.12.0). Dec 21 00:01:09 unbound 43483 [43483:0] info: service stopped (unbound 1.12.0). Dec 21 00:01:14 unbound 53896 [53896:0] info: start of service (unbound 1.12.0). Dec 21 00:07:55 unbound 53896 [53896:0] info: service stopped (unbound 1.12.0). Dec 21 00:08:02 unbound 67826 [67826:0] info: start of service (unbound 1.12.0). Dec 21 00:15:59 unbound 67826 [67826:0] info: service stopped (unbound 1.12.0). Dec 21 00:16:06 unbound 80976 [80976:0] info: start of service (unbound 1.12.0). Dec 22 00:01:09 unbound 80976 [80976:0] info: service stopped (unbound 1.12.0). Dec 22 00:01:14 unbound 58354 [58354:0] info: start of service (unbound 1.12.0). Dec 26 00:03:51 unbound 10555 [10555:0] info: start of service (unbound 1.12.0). Dec 28 01:49:32 unbound 93171 [93171:0] info: start of service (unbound 1.12.0). Dec 28 04:27:58 unbound 93171 [93171:0] info: service stopped (unbound 1.12.0). Dec 28 04:28:04 unbound 72678 [72678:0] info: start of service (unbound 1.12.0). Dec 28 04:28:28 unbound 72678 [72678:1] info: resolving ns2.dynamicnetworkservices.net. AAAA IN Dec 28 04:28:28 unbound 72678 [72678:1] info: response for ns2.dynamicnetworkservices.net. AAAA IN Dec 28 04:28:28 unbound 72678 [72678:1] info: response for ns2.dynamicnetworkservices.net. AAAA IN Dec 28 04:28:28 unbound 72678 [72678:1] info: reply from <dynamicnetworkservices.net.> 208.78.70.136#53 Dec 28 04:28:28 unbound 72678 [72678:1] info: response for ns2.dynamicnetworkservices.net. AAAA IN Dec 28 04:28:28 unbound 72678 [72678:1] info: reply from <dynamicnetworkservices.net.> 208.78.71.136#53 Dec 28 04:32:54 unbound 72678 [72678:0] info: service stopped (unbound 1.12.0). Dec 28 04:33:01 unbound 1867 [1867:0] info: start of service (unbound 1.12.0). Dec 28 12:48:51 unbound 1867 [1867:0] info: service stopped (unbound 1.12.0). Dec 28 12:48:59 unbound 11903 [11903:0] info: start of service (unbound 1.12.0). Dec 28 12:59:58 unbound 11903 [11903:0] info: service stopped (unbound 1.12.0). Dec 28 13:00:05 unbound 18980 [18980:0] info: start of service (unbound 1.12.0). -
This post is deleted! -
@cabledude said in Unbound stop/start after enabling split DNS:
Is it common to see the DNS resolver stop/start, given the default config
Not in ones I've seen. Generally it will 1) stay running, and 2) if it crashes, something needs to start it. For instance do you have the watchdog package running? Otherwise that implies it's an intentional stop/start. I don't recall if it will restart if an interface goes down/up...might check your logs for other things at the same time.
-
@steveits said in Unbound stop/start after enabling split DNS:
For instance do you have the watchdog package running?
No I don't
Otherwise that implies it's an intentional stop/start. I don't recall if it will restart if an interface goes down/up...might check your logs for other things at the same time.
Well there are lots of stop/start events on the hour, which I thought are triggered by pfBlocker, but I'm not sure:
From the General log:Dec 28 13:00:00 php 8236 [pfBlockerNG] Starting cron process. Dec 28 13:00:39 php 8236 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Dec 28 13:01:17 nginx 2021/12/28 13:01:17 [crit] 94466#100087: *7873 SSL_write() failed (13: Permission denied) while processing HTTP/2 connection, client: 172.16.120.2, server: 0.0.0.0:10443Concurrently, from the DNS Resolver log, filtered for "service":
Dec 28 12:59:58 unbound 11903 [11903:0] info: service stopped (unbound 1.12.0). Dec 28 13:00:05 unbound 18980 [18980:0] info: start of service (unbound 1.12.0).Thus, two seconds before the cron job the DNS Resolver stops, then 7 seconds later it starts. Although the cron jobs start every hour on the hour, the stop/start events are not.
I don't recall if it will restart if an interface goes down/up...might check your logs for other things at the same time.
I checked the other logs, no coinciding log events except for the "radvd" events under "routing", which show up pretty much all on the very same time stamp values.
-
@steveits said in Unbound stop/start after enabling split DNS:
For instance do you have the watchdog package running? Otherwise that implies it's an intentional stop/start.
These words keep lingering in my head. At first when you said it's not normal for these DNS Resolver service stop/start events to occur, I was a bit smitten as I recently did a complete start to finish reinstall and already I have quite an annoying issue on my hands.
Rethinkin this now I think I just need to find what is intentionally stopping/starting this service.
Maybe here is a clue:
There was this one time when the service must have been disabled for way more than a couple of seconds because I was trying to get some admin work done on my Synology NAS, while being off site. I remember struggling for at least ten minutes trying to access menus in the NAS that require external resources such as synology account servers. Eventually I decided to test other sites and then I quickly ended up checking the pfSense dash and I noticed the DNS service was stopped.As I was off site, I used different methods to access my network:
- HTTPS directly into the NAS via reverse proxy (a port 443 forward in pfSense)
- Remote Access OpenVPN as configured in pfSense
I am not sure which method I used when, but the time stamps of DNS server stop events coincide with the time frame I was doing the maintenance work. I used one of the methods 1 or 2 (or both simultaneously) I can't remember precisely.
I haven't used method 1 for quite some hours now and I don't see any service stop events yet. will keep an eye on it and will keep you posted...
Pete
-
@SteveITS
Oh well just forget method 1: I deployed that last week and stop/start events go way back even to November.Sorry.
-
@cabledude Do you have pfBlocker DNSBL enabled? I don't use that feature but maybe that's related?
Is it low on RAM and/or been on for a long time? There is the pcscd memory leak, patch is here.
-
@steveits said in Unbound stop/start after enabling split DNS:
Do you have pfBlocker DNSBL enabled? I don't use that feature but maybe that's related?
Yes I do.
Is it low on RAM and/or been on for a long time?
Not low on RAM, has been on a couple of months
There is the pcscd memory leak, patch is here.
Yes thanks that was on my list. Just applied the patch. Peculiar: I still needed to stop the pcscd daemon manually but that may be because I also had started it manually half an hour before to see how it behaves.
Now here is an observation that may or may not be interesting, I would care to hear your thoughts on this:
Do you remember I wrote that one time the DNS service was stopped and didn't restart automatically so I had to start it manually? So I went to the dashboard and navigated to Services Status and started DNS. The very second it was running, the pcscd service was stopped by the system (not by me). At that point I didn't know this daemon exists and I didn't think this stop event was relevant to this topic. But apparently there is a relationship between the two.Pete
-
@cabledude There shouldn't be any sort of tie between the two. The patch is supposed to disable the smart card service. Maybe it got stopped once you "touched" the services?