Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    pfSense 2.7 DNS Resolver doesn't start

    DHCP and DNS
    7
    36
    3.3k
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • S
      SergBrNord @Gertjan
      last edited by

      @Gertjan "Status > DNS Resolver" screenshot was taken before unbound was restarted. After restarting, page looks something like yours. About packages... I uninstalled packages, but it didn't help.

      I don't see anything suspicious in the logs. Maybe resolv.conf is corrupted?
      general_log.txt

      GertjanG 1 Reply Last reply Reply Quote 0
      • GertjanG
        Gertjan @SergBrNord
        last edited by

        @SergBrNord said in pfSense 2.7 DNS Resolver doesn't start:

        Maybe resolv.conf is corrupted?

        [23.05.1-RELEASE][root@pfSense.your-pfsense-dmain.tld]/root: cat /etc/resolv.conf
nameserver 127.0.0.1
search your-pfsense-domain.tld

        Pretty sure yours looks the same.

        Your log :

        Jul 13 09:49:37	ppp	10006	Multi-link PPP daemon for FreeBSD

        at that moment, unbound is already running.
        'ppp' kicks in, as you use pppoe. ppp will create your pppoe WAN connection.
        When done, after :

        Jul 13 09:49:55	ppp	10006	[wan] 104.124.27.174 -> 104.124.16.1

        your pfSense has a new interface.
        The system needs to be made aware of this, so 'packages' get restarted.
        This will also restart unbound once.
        So, IMHO, this explains the unbound restart after the initial boot.

        No "help me" PM's please. Use the forum, the community will thank you.
        Edit : and where are the logs ??

        S 1 Reply Last reply Reply Quote 0
        • S
          SergBrNord @Gertjan
          last edited by

          @Gertjan sounds logical.

          Here is what I found.
          I have installed the Service_Watchdog package and configured it to restart unbound service. But! Unbound didn't restart.
          It appears, that unbound is running, but for some reason it is not resolving.

          That is, before restarting, it is not getting DNS servers for some reason... what?

          P.S.
          "Allow DNS server list overridden" checked in "System>General Setup.

          johnpozJ GertjanG 2 Replies Last reply Reply Quote 0
          • johnpozJ
            johnpoz LAYER 8 Global Moderator @SergBrNord
            last edited by

            @SergBrNord said in pfSense 2.7 DNS Resolver doesn't start:

            "Allow DNS server list overridden" checked in "System>General Setup.

            That has nothing to do with unbound in resolver mode. That is to allow pfsense to get dns from its dhcp server. Pfsense itself could use those to resolve if unbound is not working.

            Your problem is most likely because of the after startup starting of your pppoe connection as gone over by @Gertjan

            An intelligent man is sometimes forced to be drunk to spend time with his fools
            If you get confused: Listen to the Music Play
            Please don't Chat/PM me for help, unless mod related
            SG-4860 24.03 | Lab VMs 2.7.2, 24.03

            S 1 Reply Last reply Reply Quote 0
            • S
              SergBrNord @johnpoz
              last edited by

              @johnpoz I have pfSense 2.6.0 on exactly the same hardware, there too there are unbound (1.13.2) restarts after PPPoE, but it works after reboot correctly.

              Well... I need a freshly installed 2.7.0 to check the repeatability.

              1 Reply Last reply Reply Quote 0
              • GertjanG
                Gertjan @SergBrNord
                last edited by

                @SergBrNord said in pfSense 2.7 DNS Resolver doesn't start:

                "Allow DNS server list overridden" checked in "System>General Setup.

                This one :

                44ca72ec-d419-45c9-ab98-866fc6e028cf-image.png

                Not checked by default, as it handles a rare case situation. Example : here :
                In your log :

                Jul 13 09:49:55	ppp	10006	[wan] IPADDR 104.124.27.174
Jul 13 09:49:55	ppp	10006	[wan] 104.124.27.174 is OK
Jul 13 09:49:55	ppp	10006	[wan] PRIDNS 134.158.196.137
Jul 13 09:49:55	ppp	10006	[wan] SECDNS 134.158.196.141
Jul 13 09:49:55	ppp	10006	[wan] IPCP: SendConfigReq #3
Jul 13 09:49:55	ppp	10006	[wan] IPADDR 104.124.27.174
Jul 13 09:49:55	ppp	10006	[wan] PRIDNS 134.158.196.137
Jul 13 09:49:55	ppp	10006	[wan] SECDNS 134.158.196.141
Jul 13 09:49:55	ppp	10006	[wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Jul 13 09:49:55	ppp	10006	[wan] IPADDR 104.124.27.174
Jul 13 09:49:55	ppp	10006	[wan] PRIDNS 134.158.196.137
Jul 13 09:49:55	ppp	10006	[wan] SECDNS 134.158.196.141

                pppoe (your ISP) gave a an IP 1x4.124.27.1x4 and two DNSs. This was needed in the past, as resolving wasn't a thing (way to slow - your your ISP wanted to limit outgoing DNS request, or simply is curious what site you wanted to visit (so they can 'use' (laos know as 'sell' your DNS usage data ) - or just offer you a somewhat faster ISP DNS cache).
                These days, you typically don't care anymore.
                You use DHCP-client on WAN and you receive an upstream DNS 'suggested' or, like your situation : pppoe : you receive two (ISP) DNS server IPs 134.158.196.137 & 134.158.196.141 : very nice of them, but you don't care. You have a resolver, you resolve.

                Have a look at this page :
                https://docs.netgate.com/pfsense/en/latest/releases/2-7-0.html

                I don't know if you are using pfSense for a long time, and thus aware (?) of some unbound issues

                Btw :

                @SergBrNord said in pfSense 2.7 DNS Resolver doesn't start:

                I have installed the Service_Watchdog package and configured it to restart unbound service.

                Very wrong .....
                Unbound only stops if it is signaled to do so.
                It could be you, with the the 'kill' command.
                Or some pfSense script that restarts processes and unbound is just one of them.

                There is no such a thing as 'stop' unbound. (exception : maybe you clicking on :

                0dbf4e65-ecf6-445b-86c5-7da170c2dc14-image.png

                but I'm sure you didn't do that.)

                So when you see a "info: service stopped (unbound 1.17.1)." it will always be followed by a "info: start of service (unbound 1.17.1)."

                If, at that moment, the Service_Watchdog detects that unbound stopped (it doesn't know anything about who why etc) it will start unbound.
                Chances are huge that now two instances try to start.
                That will break things for sure.
                Only system developers should use this Service_Watchdog package.
                Make live easier on yourself : remove Service_Watchdog.

                have a look at this page : https://docs.netgate.com/pfsense/en/latest/releases/2-7-0.html
                Ctrl-F for unbound.
                There were some issues with unbound, under 'I don't know what' circumstances.
                For myself, running unbound on a native Intel device (a 4100) I never had any of these issues.

                My unbound only restarts when a pfSEnse package 'pfBlockerng' does it's thing (updating DNS related files), and that once or twice a week.

                No "help me" PM's please. Use the forum, the community will thank you.
                Edit : and where are the logs ??

                S 1 Reply Last reply Reply Quote 1
                • S
                  SergBrNord @Gertjan
                  last edited by

                  @Gertjan thanks for the advice. I have been using pfSense for a few months now.
                  For now I will experiment with the freshly installed 2.7.0 on similar hardware. I'll let you know later what happens.

                  1 Reply Last reply Reply Quote 0
                  • T
                    TampertK
                    last edited by

                    I'm experiencing the same problem, after every (re)boot Unbound fails to start. Doing a manual start via 'Status' -> 'Services' then starts Unbound without any issue. This is on a fresh install of 2.7, on which I've restored a previously working config file.

                    My logs show this:

                    fatal error: Could not read config file: /unbound.conf. Maybe try unbound -dd, it stays on the commandline to see more errors, or unbound-checkconf

                    But then running the 'unbound -dd' command returns no errors.

                    My connection is also PPPoE based, but I don't use the ISP provided DNS servers. Instead I use Cloudflare and Quad9 in DoT forwarding mode. Besides that, I have Wireguard installed.

                    GertjanG 1 Reply Last reply Reply Quote 0
                    • GertjanG
                      Gertjan @TampertK
                      last edited by

                      @TampertK

                      Before unbound is started, it's chrooted into /var/unbound/
                      Have a look at that folder, there should be a "unbound.conf" file.
                      Because unbound needs several system files and libraries, these folders are also placed into /var/unbound/, like /var/log/ (for logging to resolver.log), /lib and /dev and /usr/local/lib, bin and share/GeoIP

                      Have your system rebooted, and as soon as possible, see what is logged in /var/log/system.log, in parallel with /var/log/resolver.log

                      If there are any file system issues, that would explain why unbound couldn't start.

                      First : make a pfSense config backup.

                      Something to test/try : restore the unbound config to default - you will be resolving now and not forwarding anymore. This means that Cloudflare and Quad9 won't receive all your private DNS requests anymore. Not a big deal.
                      Or even better : restore pfSense to default. Set up just ONE thing : your WAN access (you use pppoe).
                      Do not change anything else.

                      @TampertK said in pfSense 2.7 DNS Resolver doesn't start:

                      I don't use the ISP provided DNS servers

                      That, "ISP provided DNS servers" was an option, sometimes needed way in the past, as your ISP wanted you to use their DNS servers, just to put less strain on POPs to others hosts / entities. These days, no one uses ISP DNS servers anymore, as it is not their job. Exception maybe : satellite providers, as their links costs a lot, or some other very special type of ISP.
                      Remember : these are the modern days. Forwarding is not a thing anymore. It exists, so 'they' can make money (or 'knowledge, but's that also money at the end of the line) over your back with your data.
                      Internet itself was build in around 1960/70 with DNS root servers in mind. Their addresses are build into the resolver.
                      Just think about it : if you needed some external resolver for pfSEnse to work with, the list was build into pfSense. Guess what : there is none. As none are needed.

                      No "help me" PM's please. Use the forum, the community will thank you.
                      Edit : and where are the logs ??

                      T 1 Reply Last reply Reply Quote 0
                      • T
                        TampertK @Gertjan
                        last edited by

                        @Gertjan Thanks for your help. I'm not sure what to look for in /var/log/system.log, as I see no obvious errors. I so see these entries around every reboot, but nothing has changed regarding IPv6 to my connection (there is no IPv6...) There is nothing error-related around reboot in /var/log/resolver.log either.

                        Jul  7 14:50:35 pfSense php-cgi[433]: rc.bootup: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
Jul  7 14:50:35 pfSense kernel: done.
Jul  7 14:50:36 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:37 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:38 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:39 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:40 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:41 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:42 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:43 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:44 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:45 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
Jul  7 14:50:47 pfSense php-cgi[433]: rc.bootup: sync unbound done.

                        More worryingly, today Unbound just stopped randomly, with these entries in /var/log/resolver.log

                        Jul 27 11:36:43 pfSense unbound[55305]: [55305:0] info: service stopped (unbound 1.17.1).
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 0: 217676 queries, 205849 answers from cache, 11827 recursions, 85435 prefetch, 0 rejected by ip ratelimiting
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 0: requestlist max 27 avg 0.457507 exceeded 0 jostled 0
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: average recursion processing time 0.117910 sec
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: histogram of recursion processing times
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: [25%]=0.00668812 median[50%]=0.0199249 [75%]=0.0507544
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: lower(secs) upper(secs) recursions
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.000000    0.000001 1300
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.000064    0.000128 1
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.000128    0.000256 1
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.000512    0.001024 4
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.001024    0.002048 4
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.002048    0.004096 96
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.004096    0.008192 2439
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.008192    0.016384 1558
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.016384    0.032768 2295
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.032768    0.065536 2096
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.065536    0.131072 1156
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.131072    0.262144 348
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.262144    0.524288 166
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.524288    1.000000 115
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    1.000000    2.000000 73
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    2.000000    4.000000 87
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    4.000000    8.000000 34
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    8.000000   16.000000 18
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:   16.000000   32.000000 7
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 1: 238090 queries, 227071 answers from cache, 11019 recursions, 80655 prefetch, 0 rejected by ip ratelimiting
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: server stats for thread 1: requestlist max 32 avg 0.452058 exceeded 0 jostled 0
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: average recursion processing time 0.121988 sec
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: histogram of recursion processing times
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: [25%]=0.00714891 median[50%]=0.0223932 [75%]=0.0535574
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info: lower(secs) upper(secs) recursions
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.000000    0.000001 1176
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.000128    0.000256 1
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.000512    0.001024 1
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.001024    0.002048 4
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.002048    0.004096 88
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.004096    0.008192 1985
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.008192    0.016384 1425
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.016384    0.032768 2233
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.032768    0.065536 2105
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.065536    0.131072 1205
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.131072    0.262144 318
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.262144    0.524288 140
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    0.524288    1.000000 101
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    1.000000    2.000000 77
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    2.000000    4.000000 80
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    4.000000    8.000000 38
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:    8.000000   16.000000 12
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:   16.000000   32.000000 8
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] info:   32.000000   64.000000 1
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] notice: Restart of unbound 1.17.1.
Jul 27 11:36:44 pfSense unbound[55305]: [55305:0] fatal error: Could not read config file: /unbound.conf. Maybe try unbound -dd, it stays on the commandline to see more errors, or unbound-checkconf

                        The logs indicate Unbound is being restarted, but it just seems to hang instead. The service appears as stopped, and requires a manual start.

                        1 Reply Last reply Reply Quote 0
                        • GertjanG
                          Gertjan @SergBrNord
                          last edited by Gertjan

                          Remember this one :

                          @SergBrNord said in pfSense 2.7 DNS Resolver doesn't start:

                          I'm not using DHCP, it's disabled, unbound working in resolve mode.

                          I saw what you saw :
                          Jul 7 14:50:36 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:37 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:38 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:39 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:40 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:41 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:42 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:43 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:44 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.
                          Jul 7 14:50:45 pfSense php-cgi[433]: rc.bootup: Unbound start waiting on dhcp6c.

                          So, - ok, silly joke, you are using DHCP.

                          First line : rc.bootup: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'

                          dhcp6c is the client process, normally activated on WAN interface, so it can deliver IPv6 info to the system, like a IPv6 gateway, IP, DNS, and prefixes.

                          dhcp6c fails, that's for sure.

                          What about : on your WAN interface : set

                          66173693-31c6-474f-98d8-91b19c61cf78-image.png

                          and call it a day.

                          Or : ask pfSense / dhcp6c what's up.
                          Start by :

                          System > Advanced > Networking and check "DHCP6 Debug".

                          From now on, in the DHCP log you'll see what happens, what the dhcpv6 has to say.

                          No "help me" PM's please. Use the forum, the community will thank you.
                          Edit : and where are the logs ??

                          T 1 Reply Last reply Reply Quote 0
                          • T
                            TampertK @Gertjan
                            last edited by

                            @Gertjan Perhaps @SergBrNord does not use DHCP, I do and never claimed otherwise :)

                            My WAN interface indeed had 'DHCP6' set as 'IPv6 Configuration Type', but in System/Advanced/Networking 'Allow IPv6' was unchecked (= disabled). Setting 'IPv6 Configuration Type' to 'None' fixes the issue of Unbound not starting at boot, I'll monitor for random halts. Interesting that this has not been an issue up until 2.7, my config did not change.

                            1 Reply Last reply Reply Quote 0
                            • T
                              TampertK
                              last edited by TampertK

                              This post is deleted!
                              1 Reply Last reply Reply Quote 0
                              • T
                                TampertK
                                last edited by

                                Cheered too early, just had another random crash of Unbound. Digging deeper into the logs, it seems that an OpenVPN client instance may be involved. Look at the timing:

                                /var/log/openvpn.log

                                Jul 31 17:57:50 pfSense openvpn[6398]: [{OpenVPN server name}] Inactivity timeout (--ping-restart), restarting
Jul 31 17:57:50 pfSense openvpn[6398]: SIGUSR1[soft,ping-restart] received, process restarting
Jul 31 17:57:50 pfSense openvpn[6398]: Restart pause, 1 second(s)

                                /var/log/resolver.log

                                Jul 31 17:58:57 pfSense unbound[77815]: [77815:0] info: service stopped (unbound 1.17.1).

                                So OpenVPN initiates a restart, and a few seconds later Unbound crashes. I'm not using the OpenVPN server provided DNS servers (Pull DNS disabled), and the connection is set to IPv4 only Any ideas on this combo @Gertjan ?

                                johnpozJ 1 Reply Last reply Reply Quote 0
                                • johnpozJ
                                  johnpoz LAYER 8 Global Moderator @TampertK
                                  last edited by

                                  @TampertK if your unbound outbound interfaces is set to all, then the restart of any of your interfaces can cause a problem with unbound that is bound to that interface.

                                  Just use localhost as the only outbound interface. Should remove any care if some other interface resets for any reason.

                                  An intelligent man is sometimes forced to be drunk to spend time with his fools
                                  If you get confused: Listen to the Music Play
                                  Please don't Chat/PM me for help, unless mod related
                                  SG-4860 24.03 | Lab VMs 2.7.2, 24.03

                                  T 1 Reply Last reply Reply Quote 0
                                  • T
                                    TampertK @johnpoz
                                    last edited by

                                    @johnpoz Thanks for the suggestion. The outgoing interface was set to WAN, now changed to localhost. Nothing about my configuration has changed between 2.6 and 2.7, so I can't help but feel that this is a bug or regression of some sort.

                                    GertjanG 1 Reply Last reply Reply Quote 0
                                    • GertjanG
                                      Gertjan @TampertK
                                      last edited by

                                      @TampertK

                                      Just checking : you don't have the pfSense watchdog package loaded and activated for unbound ?
                                      If so, don't.

                                      Not using IPv6, and have dhcpv6 trying to get an IPv6 (and if it does work out, this will impact the WAN interface).
                                      So, as proposed : set dhcpv6 to none.

                                      You are using the OpenVPN client - and it is ordered to "ping-restart" == when ping loss, it will restart the connection.
                                      If unbound uses this VPN connection as an outgoing connection == WAN to upstream DNS servers, then unbound will restart. This means that a 'bad' upstream' connection will influence the uptime of unbound.
                                      You've set unbound outgoing to 'localhost'. This doesn't mean unbound doesn't use whatever route is available to the internet (straight WAN or VPN routed WAN) , as 'localhost' won't offer any upstream DNS servers.

                                      What device is this ? bare bone ? VM ? Netgate device, Intel or AMD ?

                                      No "help me" PM's please. Use the forum, the community will thank you.
                                      Edit : and where are the logs ??

                                      T 1 Reply Last reply Reply Quote 0
                                      • T
                                        TampertK @Gertjan
                                        last edited by

                                        @Gertjan Watchdog package is not installed.

                                        As per your earlier suggestion, I set 'IPv6 Configuration Type' on WAN to 'None'. This resolved Unbound not starting at boot, but did not resolve Unbound crashing randomly.

                                        Unbound did not use the OpenVPN client as outgoing connection, only WAN was selected under 'Outgoing Network Interfaces'. Per @johnpoz 's suggestion I've now set this to 'localhost'.

                                        My pfSense installation is running in ESXi 8, on a Dell 5070. The NICs (Intel X520) are passed through to the VM. But again, nothing has changed to the hardware or hypervisor between my 2.6 and 2.7 installations.

                                        1 Reply Last reply Reply Quote 0
                                        • L
                                          LastOfTheRonnies
                                          last edited by

                                          Hi, I believe I'm seeing a somewhat similar unbound issue.
                                          Unbound goes for a restart but does not complete the reload. This happens roughly once a week and appears to be random in terms of the time.

                                          Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: lower(secs) upper(secs) recursions
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    0.008192    0.016384 1
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    0.016384    0.032768 3
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    0.032768    0.065536 6
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    0.065536    0.131072 14
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    0.131072    0.262144 8
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    0.262144    0.524288 7
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    0.524288    1.000000 1
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info:    1.000000    2.000000 1
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] notice: Restart of unbound 1.17.1.
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] notice: init module 0: validator
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] notice: init module 1: iterator
Aug 12 07:53:44 pfSense unbound[26068]: [26068:0] info: start of service (unbound 1.17.1).
Aug 12 07:55:31 pfSense unbound[26068]: [26068:1] info: generate keytag query _ta-4f66. NULL IN
Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: service stopped (unbound 1.17.1).
Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: server stats for thread 0: 1850 queries, 788 answers from cache, 1062 recursions, 0 prefetch, 0 rejected by ip ratelimit
ing
Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: server stats for thread 0: requestlist max 56 avg 4.08569 exceeded 0 jostled 0
Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: average recursion processing time 0.239038 sec
Aug 12 10:03:02 pfSense unbound[26068]: [26068:0] info: histogram of recursion processing times

                                          Here we can see that unbound restarted at 07:53:44 but appears to have incompletely loaded.
                                          Interestingly the Service Status widget on the dashboard was showing that unbound was running/green-ticked.
                                          I manually restarted the service at 10:03 and it came up ok.

                                          I have OpenVPN, but there are no log entries since the 9th Aug, so it's not similar to @TampertK 's logs.
                                          I did have IPV6 Configuration Type set to DHCP6 on the WAN interface, I have changed that to None now.

                                          The system is an ALIX apu2e4 with 2.7.0-RELEASE.

                                          L 1 Reply Last reply Reply Quote 0
                                          • L
                                            LastOfTheRonnies
                                            last edited by

                                            Oh I've cursed it now! Failed again at 11:03:45!
                                            In the combined grep-log below I do see a HUP coming from dhcpd at 11:03:42, then the service fails to load afterwards...

                                            [2.7.0-RELEASE][root@pfSense.homenet.local]/var/log: grep -r -n . -i -e "Aug 12 11:03:4"
./filter.log:338:Aug 12 11:03:40 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,3949,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76
./filter.log:339:Aug 12 11:03:41 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,245,62789,0,none,6,tcp,40,79.124.62.86,109.255.17.211,58350,16502,0,S,2150868192,,1024,,
./filter.log:340:Aug 12 11:03:42 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,4249,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76
./filter.log:341:Aug 12 11:03:43 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,4546,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76
./filter.log:342:Aug 12 11:03:44 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,51,34872,0,none,17,udp,132,92.178.111.50,109.255.17.211,49732,33737,112
./filter.log:343:Aug 12 11:03:45 pfSense filterlog[40581]: 4,,,1000000103,igb0,match,block,in,4,0x0,,55,4831,0,DF,17,udp,96,188.166.128.84,109.255.17.211,3479,30112,76
./dhcpd.log:5693:Aug 12 11:03:42 pfSense dhcpleases[64065]: Sending HUP signal to dns daemon(47791)
./resolver.log:4636:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: service stopped (unbound 1.17.1).
./resolver.log:4637:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 0: 145 queries, 10 answers from cache, 135 recursions, 0 prefetch, 0 rejected by ip ratelimiting
./resolver.log:4638:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 0: requestlist max 13 avg 0.488889 exceeded 0 jostled 0
./resolver.log:4639:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.158614 sec
./resolver.log:4640:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times
./resolver.log:4641:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0383535 median[50%]=0.0945591 [75%]=0.197778
./resolver.log:4642:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions
./resolver.log:4643:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.000000    0.000001 7
./resolver.log:4644:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.008192    0.016384 5
./resolver.log:4645:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.016384    0.032768 18
./resolver.log:4646:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.032768    0.065536 22
./resolver.log:4647:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.065536    0.131072 35
./resolver.log:4648:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.131072    0.262144 28
./resolver.log:4649:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.262144    0.524288 12
./resolver.log:4650:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.524288    1.000000 6
./resolver.log:4651:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    1.000000    2.000000 2
./resolver.log:4652:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 1: 95 queries, 7 answers from cache, 88 recursions, 0 prefetch, 0 rejected by ip ratelimiting
./resolver.log:4653:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 1: requestlist max 10 avg 0.443182 exceeded 0 jostled 0
./resolver.log:4654:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.222569 sec
./resolver.log:4655:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times
./resolver.log:4656:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0512 median[50%]=0.123362 [75%]=0.297097
./resolver.log:4657:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions
./resolver.log:4658:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.000000    0.000001 7
./resolver.log:4659:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.016384    0.032768 6
./resolver.log:4660:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.032768    0.065536 16
./resolver.log:4661:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.065536    0.131072 17
./resolver.log:4662:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.131072    0.262144 18
./resolver.log:4663:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.262144    0.524288 15
./resolver.log:4664:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.524288    1.000000 7
./resolver.log:4665:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    1.000000    2.000000 1
./resolver.log:4666:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    2.000000    4.000000 1
./resolver.log:4667:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 2: 148 queries, 11 answers from cache, 137 recursions, 0 prefetch, 0 rejected by ip ratelimiting
./resolver.log:4668:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 2: requestlist max 12 avg 0.423358 exceeded 0 jostled 0
./resolver.log:4669:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.169696 sec
./resolver.log:4670:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times
./resolver.log:4671:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0385707 median[50%]=0.102085 [75%]=0.221432
./resolver.log:4672:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions
./resolver.log:4673:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.000000    0.000001 11
./resolver.log:4674:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.008192    0.016384 3
./resolver.log:4675:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.016384    0.032768 16
./resolver.log:4676:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.032768    0.065536 24
./resolver.log:4677:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.065536    0.131072 26
./resolver.log:4678:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.131072    0.262144 33
./resolver.log:4679:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.262144    0.524288 16
./resolver.log:4680:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.524288    1.000000 6
./resolver.log:4681:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    1.000000    2.000000 2
./resolver.log:4682:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 3: 211 queries, 19 answers from cache, 192 recursions, 0 prefetch, 0 rejected by ip ratelimiting
./resolver.log:4683:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: server stats for thread 3: requestlist max 6 avg 0.322917 exceeded 0 jostled 0
./resolver.log:4684:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: average recursion processing time 0.146060 sec
./resolver.log:4685:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: histogram of recursion processing times
./resolver.log:4686:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: [25%]=0.0295969 median[50%]=0.0855609 [75%]=0.2046
./resolver.log:4687:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: lower(secs) upper(secs) recursions
./resolver.log:4688:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.000000    0.000001 17
./resolver.log:4689:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.008192    0.016384 6
./resolver.log:4690:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.016384    0.032768 31
./resolver.log:4691:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.032768    0.065536 31
./resolver.log:4692:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.065536    0.131072 36
./resolver.log:4693:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.131072    0.262144 41
./resolver.log:4694:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.262144    0.524288 22
./resolver.log:4695:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    0.524288    1.000000 6
./resolver.log:4696:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info:    1.000000    2.000000 2
./resolver.log:4697:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] notice: Restart of unbound 1.17.1.
./resolver.log:4698:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] notice: init module 0: validator
./resolver.log:4699:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] notice: init module 1: iterator
./resolver.log:4700:Aug 12 11:03:42 pfSense unbound[47791]: [47791:0] info: start of service (unbound 1.17.1).
./resolver.log:4701:Aug 12 11:03:45 pfSense unbound[47791]: [47791:0] info: generate keytag query _ta-4f66. NULL IN

                                            Any clues?

                                            GertjanG 1 Reply Last reply Reply Quote 0
                                            • First post
                                              Last post