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

    DNS Resolver

    Scheduled Pinned Locked Moved
    2.2 Snapshot Feedback and Problems - RETIRED
    44
    186
    127.8k
    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.
    • H
      Hugovsky
      last edited by

      well…. spoke to soon. Can't enable "Register DHCP leases in the DNS Resolver". It refuses to start again.

      2.2-BETA (amd64)
      built on Tue Nov 25 11:18:23 CST 2014
      FreeBSD 10.1-RELEASE

      1 Reply Last reply Reply Quote 0
      • C
        cmb
        last edited by

        @Hugovsky:

        well…. spoke to soon. Can't enable "Register DHCP leases in the DNS Resolver". It refuses to start again.

        and logs what?

        1 Reply Last reply Reply Quote 0
        • H
          Hugovsky
          last edited by

          ups… sorry about that. There you go..

          System log:

          Nov 25 20:27:40 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process.
          Nov 25 20:27:40 dhcpleases: kqueue error: unkown
          Nov 25 20:27:40 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process.
          Nov 25 20:27:39 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process.

          Unbound log:

          Nov 25 20:29:40 unbound: [93575:0] fatal error: Could not read config file: /unbound.conf
          Nov 25 20:29:40 unbound: [93575:0] notice: Restart of unbound 1.4.22.
          Nov 25 20:29:40 unbound: [93575:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
          Nov 25 20:29:40 unbound: [93575:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
          Nov 25 20:29:40 unbound: [93575:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
          Nov 25 20:29:40 unbound: [93575:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
          Nov 25 20:29:40 unbound: [93575:0] info: service stopped (unbound 1.4.22).
          Nov 25 20:29:40 unbound: [93575:0] info: start of service (unbound 1.4.22).
          Nov 25 20:29:40 unbound: [93575:0] notice: init module 1: iterator
          Nov 25 20:29:40 unbound: [93575:0] notice: init module 0: validator

          BUT, this is only try if I put includes in advanced config. With default config, I can start resolver with "Register DHCP leases in the DNS Resolver" set.

          1 Reply Last reply Reply Quote 0
          • C
            cmb
            last edited by

            @Hugovsky:

            BUT, this is only try if I put includes in advanced config. With default config, I can start resolver with "Register DHCP leases in the DNS Resolver" set.

            Seems you're putting something invalid in there.

            1 Reply Last reply Reply Quote 0
            • H
              Hugovsky
              last edited by

              @cmb:

              @Hugovsky:

              BUT, this is only try if I put includes in advanced config. With default config, I can start resolver with "Register DHCP leases in the DNS Resolver" set.

              Seems you're putting something invalid in there.

              server:
              include: /conf/local-blocking-data.conf

              1 Reply Last reply Reply Quote 0
              • MikeV7896M
                MikeV7896
                last edited by

                I just set up a new 2.2 installation… unbound appears to be running, but these entries appear in the log whenever the service is started. I do have the options to register DHCP leases and static DHCP entries checked.

                Nov 25 19:15:29 unbound: [88622:0] error: cannot parse netblock: '/'
                Nov 25 19:15:29 unbound: [88622:0] error: cannot parse access control: / allow
                Nov 25 19:15:29 unbound: [88622:0] fatal error: Could not setup access control list

                Also, the service IS running, but the Status > Services page shows it as stopped.

                EDIT: Nope… it's not running. My computer is using the Google IPv6 DNS servers I put into pfSense, not the local resolver. I guess there's no way to have the router specify its own IPv6 address (even if it's link-local) for DNS to DHCP clients? I only know it's not running because my IP phone - which only supports IPv4 - can't resolve my VoIP provider hostname, and the only DNS server it has is the IPv4 LAN address of my box.

                This appears to be caused by the fact that I'm not requesting an IPv6 address on my WAN interface, just a prefix. Since there's no address, there's nothing to put in the access_lists.conf file, resulting in a access-control: / allow line.

                Bug 4046 created for this…

                The S in IOT stands for Security

                1 Reply Last reply Reply Quote 0
                • C
                  cmb
                  last edited by

                  @virgiliomi:

                  This appears to be caused by the fact that I'm not requesting an IPv6 address on my WAN interface, just a prefix. Since there's no address, there's nothing to put in the access_lists.conf file, resulting in a access-control: / allow line.

                  Pretty sure you have to be running an old version, that was fixed over a week ago.

                  1 Reply Last reply Reply Quote 0
                  • MikeV7896M
                    MikeV7896
                    last edited by

                    @cmb:

                    @virgiliomi:

                    This appears to be caused by the fact that I'm not requesting an IPv6 address on my WAN interface, just a prefix. Since there's no address, there's nothing to put in the access_lists.conf file, resulting in a access-control: / allow line.

                    Pretty sure you have to be running an old version, that was fixed over a week ago.

                    2.2-BETA (amd64)
                    built on Tue Nov 25 11:18:23 CST 2014

                    The S in IOT stands for Security

                    1 Reply Last reply Reply Quote 0
                    • MikeV7896M
                      MikeV7896
                      last edited by

                      I updated to the latest snapshot as of this morning (built on Thu Nov 27 00:15:05 CST 2014) and the above issue seems to be resolved. Now I run into something else. My computer (Win7) has both the IPv6 and v4 addresses of my box as DNS servers.  When I try to do nslookup, it appears that unbound is refusing queries to the IPv6 address, while queries via IPv4 go through no problem.

                      > [internal hostname]
Server:  UnKnown
Address:  2601:8:a00:xxx:xxx:xxx:xxx:xxx

*** UnKnown can't find [internal hostname]: Query refused

> [external hostname]
Server:  UnKnown
Address:  2601:8:a00:xxx:xxx:xxx:xxx:xxx

*** UnKnown can't find [external hostname]: Query refused

> server 192.168.1.1
Default Server:  [192.168.1.1]
Address:  192.168.1.1

> [internal hostname]
Server:  [192.168.1.1]
Address:  192.168.1.1

Name:    [internal hostname]
Address:  192.168.1.108

> [external hostname]
Server:  [192.168.1.1]
Address:  192.168.1.1

Non-authoritative answer:
Name:    [external hostname]
Addresses:  [ip addresses]

                      The S in IOT stands for Security

                      1 Reply Last reply Reply Quote 0
                      • C
                        cmb
                        last edited by

                        @virgiliomi:

                        When I try to do nslookup, it appears that unbound is refusing queries to the IPv6 address, while queries via IPv4 go through no problem.

                        That was tightened up a bit recently. It generally seems fine. The biggest functional change is it skips IPv6 subnets that reside on an Internet connection (a static interface with a gateway specified under Interfaces>[interface name], or any dynamic connection type). Is the subnet in question on an interface that's an Internet connection? Or is treated like one because a gateway is chosen under Interfaces?

                        1 Reply Last reply Reply Quote 0
                        • MikeV7896M
                          MikeV7896
                          last edited by

                          @cmb:

                          @virgiliomi:

                          When I try to do nslookup, it appears that unbound is refusing queries to the IPv6 address, while queries via IPv4 go through no problem.

                          That was tightened up a bit recently. It generally seems fine. The biggest functional change is it skips IPv6 subnets that reside on an Internet connection (a static interface with a gateway specified under Interfaces>[interface name], or any dynamic connection type). Is the subnet in question on an interface that's an Internet connection? Or is treated like one because a gateway is chosen under Interfaces?

                          No, it's actually my LAN interface, which has IPv6 as "Track Interface" (WAN, Prefix 0)… My WAN interface isn't obtaining an IPv6 address, just a /60 prefix.

                          The S in IOT stands for Security

                          1 Reply Last reply Reply Quote 0
                          • C
                            cmb
                            last edited by

                            @virgiliomi:

                            No, it's actually my LAN interface, which has IPv6 as "Track Interface" (WAN, Prefix 0)… My WAN interface isn't obtaining an IPv6 address, just a /60 prefix.

                            Ok I see what was happening there, that was fixed today. Should be good on tomorrow's snapshot, or gitsync now.

                            1 Reply Last reply Reply Quote 0
                            • M
                              mattbunce
                              last edited by

                              Are entries posted in "Domain Overrides" being processed correctly?

                              I want to route any requests for hosts on the other end of my vpn to the pfSense that runs that network. This is something I had working perfectly using "Domain Overrides" within the old DNS Forwarder, but using DNS resolver it doesn't seem to be working.

                              My current config has the domain is set "vpn" and the server to forward these requests to is "10.30.1.1"

                              Are there any particular settings I should be looking at to get this to work?

                              Here is my log for an nslookup from my local network to server.vpn (Server is a valid dns entry on the other network and like I said, these queries were working with DNS Forwarder).

                              Looking at the log, I can see entires such as "server.vpn.local." - Why has the "local" been added to this query? (local, as your probably guessed is the DNS suffix for my local lan). My WAN DNS servers are Google (8.8.x.x) and Level 3 (209.244.x.x) and you can see that queries are being sent to these as well as 10.30.1.1 (the server which should be able to give us a result).

                              
01/11/2029 01:53	unbound: [20144:0] info: start of service (unbound 1.4.22).
01/11/2029 01:53	unbound: [20144:2] debug: cache memory msg=66554 rrset=67202 infra=3849 val=0
01/11/2029 01:53	unbound: [20144:2] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 01:53	unbound: [20144:2] info: sending query: server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: processQueryTargets: server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: resolving (init part 3): server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: use stub vpn. NS IN
01/11/2029 01:53	unbound: [20144:2] info: resolving (init part 2): server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: use stub vpn. NS IN
01/11/2029 01:53	unbound: [20144:2] info: resolving server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
01/11/2029 01:53	unbound: [20144:3] debug: cache memory msg=66554 rrset=67202 infra=3596 val=0
01/11/2029 01:53	unbound: [20144:3] info: finishing processing for server.vpn.local. AAAA IN
01/11/2029 01:53	unbound: [20144:3] info: query response was NXDOMAIN ANSWER
01/11/2029 01:53	unbound: [20144:3] info: reply from <.> 8.8.4.4#53
01/11/2029 01:53	unbound: [20144:3] info: response for server.vpn.local. AAAA IN
01/11/2029 01:53	unbound: [20144:3] info: iterator operate: query server.vpn.local. AAAA IN
01/11/2029 01:53	unbound: [20144:3] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
01/11/2029 01:53	unbound: [20144:3] debug: cache memory msg=66313 rrset=67202 infra=3596 val=0
01/11/2029 01:53	unbound: [20144:3] debug: sending to target: <.> 8.8.4.4#53
01/11/2029 01:53	unbound: [20144:3] info: sending query: server.vpn.local. AAAA IN
01/11/2029 01:53	unbound: [20144:3] info: processQueryTargets: server.vpn.local. AAAA IN
01/11/2029 01:53	unbound: [20144:3] info: resolving server.vpn.local. AAAA IN
01/11/2029 01:53	unbound: [20144:3] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
01/11/2029 01:53	unbound: [20144:0] debug: cache memory msg=66313 rrset=67202 infra=3347 val=0
01/11/2029 01:53	unbound: [20144:0] info: finishing processing for server.vpn.local. A IN
01/11/2029 01:53	unbound: [20144:0] info: query response was NXDOMAIN ANSWER
01/11/2029 01:53	unbound: [20144:0] info: reply from <.> 209.244.0.3#53
01/11/2029 01:53	unbound: [20144:0] info: response for server.vpn.local. A IN
01/11/2029 01:53	unbound: [20144:0] info: iterator operate: query server.vpn.local. A IN
01/11/2029 01:53	unbound: [20144:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
01/11/2029 01:53	unbound: [20144:0] debug: cache memory msg=66072 rrset=66072 infra=3347 val=0
01/11/2029 01:53	unbound: [20144:0] debug: sending to target: <.> 209.244.0.3#53
01/11/2029 01:53	unbound: [20144:0] info: sending query: server.vpn.local. A IN
01/11/2029 01:53	unbound: [20144:0] info: processQueryTargets: server.vpn.local. A IN
01/11/2029 01:53	unbound: [20144:0] info: resolving server.vpn.local. A IN
01/11/2029 01:53	unbound: [20144:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
01/11/2029 01:53	unbound: [20144:2] debug: cache memory msg=66554 rrset=67202 infra=3849 val=0
01/11/2029 01:53	unbound: [20144:2] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 01:53	unbound: [20144:2] info: sending query: server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: processQueryTargets: server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: iterator operate: query server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
01/11/2029 01:53	unbound: [20144:2] debug: cache memory msg=66554 rrset=67202 infra=3849 val=0
01/11/2029 01:53	unbound: [20144:2] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 01:53	unbound: [20144:2] info: sending query: server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: processQueryTargets: server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] info: iterator operate: query server.vpn. A IN
01/11/2029 01:53	unbound: [20144:2] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply</vpn.></vpn.></vpn.>
                              1 Reply Last reply Reply Quote 0
                              • P
                                phil.davis
                                last edited by

                                @mattbunce - have a read of this thread: https://forum.pfsense.org/index.php?topic=84184.0
                                Perhaps now the unbound requests are going out with source IP as the VPN tunnel local end-point, and the DNS server at 10.30.1.1 does not have a route back to that?
                                In DNS Forwarder (dnsmasq) you might have been using the "Source IP" field in the Domain Overrides settings to help this. But that field no longer exists for DNS Resolver (unbound).

                                Edit: add: Your client will be adding anything in its DNS suffix searchlist automatically, thus tryin server.vpn.local as well as server.vpn
                                Put the terminating "." at the end of the name to stop that;

                                nslookup server.vpn.

                                As the Greek philosopher Isosceles used to say, "There are 3 sides to every triangle."
                                If I helped you, then help someone else - buy someone a gift from the INF catalog http://secure.inf.org/gifts/usd/

                                1 Reply Last reply Reply Quote 0
                                • MikeV7896M
                                  MikeV7896
                                  last edited by

                                  So Unbound seems to have an issue where it restarts about every 70 minutes. Unfortunately I turned down the log verbosity because it was generating a massive amount of data even at level 1. So all I have are the start/stop entries. But here's a bit of the log…

                                  Nov 28 00:41:25	unbound: [18673:0] info: service stopped (unbound 1.4.22).
Nov 28 00:41:25	unbound: [18673:0] info: start of service (unbound 1.4.22).
Nov 28 01:50:49	unbound: [18673:0] info: service stopped (unbound 1.4.22).
Nov 28 01:50:49	unbound: [18673:0] info: start of service (unbound 1.4.22).
Nov 28 03:00:08	unbound: [18673:0] info: service stopped (unbound 1.4.22).
Nov 28 03:00:08	unbound: [18673:0] info: start of service (unbound 1.4.22).
Nov 28 04:09:24	unbound: [18673:0] info: service stopped (unbound 1.4.22).
Nov 28 04:09:24	unbound: [18673:0] info: start of service (unbound 1.4.22).
Nov 28 05:18:43	unbound: [18673:0] info: service stopped (unbound 1.4.22).
Nov 28 05:18:43	unbound: [18673:0] info: start of service (unbound 1.4.22).
Nov 28 06:23:57	unbound: [18673:0] info: service stopped (unbound 1.4.22).
Nov 28 06:23:57	unbound: [18673:0] info: start of service (unbound 1.4.22).

                                  I'll turn the verbosity back up and see if it provides any further enlightenment tomorrow… but given how much data it puts in that log file, it might be a bit harder to tell.

                                  The S in IOT stands for Security

                                  1 Reply Last reply Reply Quote 0
                                  • M
                                    mattbunce
                                    last edited by

                                    Hi, thanks for your help, reading that did lead me to something else… I'm not entirely sure what the "source IP" box was under DNS Forwarder, but I don't think I was using it. The only change I ever made was adding a couple of domains to the "DNS overrides" section.

                                    I have realised a big error on my part though, I had set DNS Resolver to only use WAN, so without access to the VPN it could never send the request to the other server - Whoops!

                                    So now I am getting a result, but it is slow, since the query is also being sent to my main WAN DNS servers, you can see this in the log below.

                                    It seems strange that DNS resolver has identified this as a query that should be sent via the VPN, but it still sends it to the main DNS servers?

                                    
NOTE: MOST RECENT ENTRIES AT TOP

01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=67178 rrset=67824 infra=3600 val=0
01/11/2029 11:12	unbound: [47949:0] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 11:12	unbound: [47949:0] info: sending query: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: processQueryTargets: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: iterator operate: query server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=67178 rrset=67824 infra=3600 val=0
01/11/2029 11:12	unbound: [47949:0] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 11:12	unbound: [47949:0] info: sending query: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: processQueryTargets: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: iterator operate: query server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=67178 rrset=67824 infra=3600 val=0
01/11/2029 11:12	unbound: [47949:0] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 11:12	unbound: [47949:0] info: sending query: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: processQueryTargets: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: iterator operate: query server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=67178 rrset=67824 infra=3600 val=0
01/11/2029 11:12	unbound: [47949:0] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 11:12	unbound: [47949:0] info: sending query: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: processQueryTargets: server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: resolving (init part 3): server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: use stub vpn. NS IN
01/11/2029 11:12	unbound: [47949:0] info: resolving (init part 2): server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: use stub vpn. NS IN
01/11/2029 11:12	unbound: [47949:0] info: resolving server.vpn. AAAA IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=67178 rrset=67824 infra=3600 val=0
01/11/2029 11:12	unbound: [47949:0] info: finishing processing for server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] info: query response was ANSWER
01/11/2029 11:12	unbound: [47949:0] info: reply from <vpn.>10.30.1.1#53
01/11/2029 11:12	unbound: [47949:0] info: response for server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] info: iterator operate: query server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=66990 rrset=67638 infra=3600 val=0
01/11/2029 11:12	unbound: [47949:0] debug: sending to target: <vpn.>10.30.1.1#53
01/11/2029 11:12	unbound: [47949:0] info: sending query: server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] info: processQueryTargets: server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] info: resolving (init part 3): server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] info: use stub vpn. NS IN
01/11/2029 11:12	unbound: [47949:0] info: resolving (init part 2): server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] info: use stub vpn. NS IN
01/11/2029 11:12	unbound: [47949:0] info: resolving server.vpn. A IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=66990 rrset=67638 infra=3347 val=0
01/11/2029 11:12	unbound: [47949:0] info: finishing processing for server.vpn.local. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: query response was NXDOMAIN ANSWER
01/11/2029 11:12	unbound: [47949:0] info: reply from <.> 8.8.4.4#53
01/11/2029 11:12	unbound: [47949:0] info: response for server.vpn.local. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: iterator operate: query server.vpn.local. AAAA IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
01/11/2029 11:12	unbound: [47949:0] debug: cache memory msg=66749 rrset=67638 infra=3347 val=0
01/11/2029 11:12	unbound: [47949:0] debug: sending to target: <.> 8.8.4.4#53
01/11/2029 11:12	unbound: [47949:0] info: sending query: server.vpn.local. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: processQueryTargets: server.vpn.local. AAAA IN
01/11/2029 11:12	unbound: [47949:0] info: resolving server.vpn.local. AAAA IN
01/11/2029 11:12	unbound: [47949:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
01/11/2029 11:12	unbound: [47949:1] debug: cache memory msg=66749 rrset=67638 infra=3347 val=0
01/11/2029 11:12	unbound: [47949:1] info: finishing processing for server.vpn.local. A IN
01/11/2029 11:12	unbound: [47949:1] info: query response was NXDOMAIN ANSWER
01/11/2029 11:12	unbound: [47949:1] info: reply from <.> 8.8.4.4#53
01/11/2029 11:12	unbound: [47949:1] info: response for server.vpn.local. A IN
01/11/2029 11:12	unbound: [47949:1] info: iterator operate: query server.vpn.local. A IN
01/11/2029 11:12	unbound: [47949:1] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
01/11/2029 11:12	unbound: [47949:1] debug: cache memory msg=66508 rrset=66508 infra=3347 val=0
01/11/2029 11:12	unbound: [47949:1] debug: sending to target: <.> 8.8.4.4#53
01/11/2029 11:12	unbound: [47949:1] info: sending query: server.vpn.local. A IN
01/11/2029 11:12	unbound: [47949:1] info: processQueryTargets: server.vpn.local. A IN
01/11/2029 11:12	unbound: [47949:1] info: resolving server.vpn.local. A IN</vpn.></vpn.></vpn.></vpn.></vpn.></vpn.>
                                    1 Reply Last reply Reply Quote 0
                                    • P
                                      phil.davis
                                      last edited by

                                      In the latest build,
                                      2.2-BETA (i386)
                                      built on Sat Nov 29 02:37:09 CST 2014
                                      FreeBSD 10.1-RELEASE

                                      There is a small coding logic error in /etc/inc.unbound.inc that can cause this PHP message:

                                      Warning: in_array() expects parameter 2 to be array, null given in /etc/inc/unbound.inc on line 607

                                      This code change fixes it: https://github.com/pfsense/pfsense/pull/1355

                                      If you are on this build, and using DNS Resolver (unbound) then make this fix, or move up to a later build when that comes…

                                      As the Greek philosopher Isosceles used to say, "There are 3 sides to every triangle."
                                      If I helped you, then help someone else - buy someone a gift from the INF catalog http://secure.inf.org/gifts/usd/

                                      1 Reply Last reply Reply Quote 0
                                      • D
                                        DiskWizard
                                        last edited by

                                        Good day !
                                        After today's update the main page fixed now.
                                        What about Unbound. I went into the very same issue https://forum.pfsense.org/index.php?topic=84146.msg461519#msg461519

                                        The fix people provided did the trick :)

                                        P.S. Borat is happy now.

                                        Thank you !

                                        BTW I had to put Routing-Gateways to proper values !!!

                                        1. GA-N3150M-D3P 8Gb RAM

                                        2. GA-C1037EN-EU 4GB RAM

                                        • 2,5 SATA III Solid State Drive SLIM S60
                                        1 Reply Last reply Reply Quote 0
                                        • MikeV7896M
                                          MikeV7896
                                          last edited by

                                          Additional on the start/stop issue… A snippet of log from early this morning... this basically shows up every 60-70 minutes in the log. Doesn't appear to be anything indicating why the stop/start at log level 1.

                                          Nov 29 03:15:33 unbound: [previous restart]
Nov 29 04:23:51	unbound: [3561:0] info: service stopped (unbound 1.4.22).
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 0: 265 queries, 94 answers from cache, 171 recursions, 0 prefetch
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 0: requestlist max 13 avg 1.24561 exceeded 0 jostled 0
Nov 29 04:23:51	unbound: [3561:0] info: average recursion processing time 0.087121 sec
Nov 29 04:23:51	unbound: [3561:0] info: histogram of recursion processing times
Nov 29 04:23:51	unbound: [3561:0] info: [25%]=0.0113869 median[50%]=0.034816 [75%]=0.109773
Nov 29 04:23:51	unbound: [3561:0] info: lower(secs) upper(secs) recursions
Nov 29 04:23:51	unbound: [3561:0] info: 0.000000 0.000001 33
Nov 29 04:23:51	unbound: [3561:0] info: 0.008192 0.016384 25
Nov 29 04:23:51	unbound: [3561:0] info: 0.016384 0.032768 26
Nov 29 04:23:51	unbound: [3561:0] info: 0.032768 0.065536 24
Nov 29 04:23:51	unbound: [3561:0] info: 0.065536 0.131072 30
Nov 29 04:23:51	unbound: [3561:0] info: 0.131072 0.262144 17
Nov 29 04:23:51	unbound: [3561:0] info: 0.262144 0.524288 13
Nov 29 04:23:51	unbound: [3561:0] info: 0.524288 1.000000 3
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 1: 22 queries, 12 answers from cache, 10 recursions, 0 prefetch
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 1: requestlist max 4 avg 0.4 exceeded 0 jostled 0
Nov 29 04:23:51	unbound: [3561:0] info: average recursion processing time 0.129809 sec
Nov 29 04:23:51	unbound: [3561:0] info: histogram of recursion processing times
Nov 29 04:23:51	unbound: [3561:0] info: [25%]=0.049152 median[50%]=0.131072 [75%]=0.212992
Nov 29 04:23:51	unbound: [3561:0] info: lower(secs) upper(secs) recursions
Nov 29 04:23:51	unbound: [3561:0] info: 0.008192 0.016384 1
Nov 29 04:23:51	unbound: [3561:0] info: 0.016384 0.032768 1
Nov 29 04:23:51	unbound: [3561:0] info: 0.032768 0.065536 1
Nov 29 04:23:51	unbound: [3561:0] info: 0.065536 0.131072 2
Nov 29 04:23:51	unbound: [3561:0] info: 0.131072 0.262144 4
Nov 29 04:23:51	unbound: [3561:0] info: 0.262144 0.524288 1
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 2: 48 queries, 19 answers from cache, 29 recursions, 0 prefetch
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 2: requestlist max 5 avg 0.172414 exceeded 0 jostled 0
Nov 29 04:23:51	unbound: [3561:0] info: average recursion processing time 0.126308 sec
Nov 29 04:23:51	unbound: [3561:0] info: histogram of recursion processing times
Nov 29 04:23:51	unbound: [3561:0] info: [25%]=0.03072 median[50%]=0.090112 [75%]=0.208896
Nov 29 04:23:51	unbound: [3561:0] info: lower(secs) upper(secs) recursions
Nov 29 04:23:51	unbound: [3561:0] info: 0.008192 0.016384 2
Nov 29 04:23:51	unbound: [3561:0] info: 0.016384 0.032768 6
Nov 29 04:23:51	unbound: [3561:0] info: 0.032768 0.065536 5
Nov 29 04:23:51	unbound: [3561:0] info: 0.065536 0.131072 4
Nov 29 04:23:51	unbound: [3561:0] info: 0.131072 0.262144 8
Nov 29 04:23:51	unbound: [3561:0] info: 0.262144 0.524288 4
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 3: 199 queries, 77 answers from cache, 122 recursions, 0 prefetch
Nov 29 04:23:51	unbound: [3561:0] info: server stats for thread 3: requestlist max 17 avg 0.967213 exceeded 0 jostled 0
Nov 29 04:23:51	unbound: [3561:0] info: average recursion processing time 0.088529 sec
Nov 29 04:23:51	unbound: [3561:0] info: histogram of recursion processing times
Nov 29 04:23:51	unbound: [3561:0] info: [25%]=0.0191147 median[50%]=0.0521309 [75%]=0.112503
Nov 29 04:23:51	unbound: [3561:0] info: lower(secs) upper(secs) recursions
Nov 29 04:23:51	unbound: [3561:0] info: 0.000000 0.000001 16
Nov 29 04:23:51	unbound: [3561:0] info: 0.008192 0.016384 11
Nov 29 04:23:51	unbound: [3561:0] info: 0.016384 0.032768 21
Nov 29 04:23:51	unbound: [3561:0] info: 0.032768 0.065536 22
Nov 29 04:23:51	unbound: [3561:0] info: 0.065536 0.131072 30
Nov 29 04:23:51	unbound: [3561:0] info: 0.131072 0.262144 12
Nov 29 04:23:51	unbound: [3561:0] info: 0.262144 0.524288 9
Nov 29 04:23:51	unbound: [3561:0] info: 0.524288 1.000000 1
Nov 29 04:23:51	unbound: [3561:0] notice: Restart of unbound 1.4.22.
Nov 29 04:23:51	unbound: [3561:0] notice: init module 0: validator
Nov 29 04:23:51	unbound: [3561:0] notice: init module 1: iterator
Nov 29 04:23:51	unbound: [3561:0] info: start of service (unbound 1.4.22).
Nov 29 05:24:32 unbound: [next restart]

                                          Is this to be expected for some reason? If so, what's the reason? Is it due to a setting I can turn off? I've been surfing when it happens and all of a sudden I get DNS errors because the service is restarting. It's a bit annoying.

                                          The S in IOT stands for Security

                                          1 Reply Last reply Reply Quote 0
                                          • P
                                            phil.davis
                                            last edited by

                                            Does the pid [3561:0] remain the same as previously?
                                            If so, then it is getting a message to reload its config, and I guess spitting out all that log stuff as it resets itdelf. That is still annoying if it has noticeable time when it is not responding to queries.

                                            What is in the system log around that time?

                                            Maybe there are real events happening - WAN down/up, a VPN down/up… that have caused it.

                                            As the Greek philosopher Isosceles used to say, "There are 3 sides to every triangle."
                                            If I helped you, then help someone else - buy someone a gift from the INF catalog http://secure.inf.org/gifts/usd/

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