DNS Resolver
-
@cmb:
It'd be nice to have that back if you'd like to put in a pull request Phil. If not, it's not a big deal.
Yes, I will have a look. It should be just a copy-paste-search-replace operation to put the same functionality into the Resolver host override aliases case.
and yes, it was that easy, pull request: https://github.com/pfsense/pfsense/pull/1344 -
@mais_um:
Edit: Can't start Resolver with DHCP Registration (Register DHCP leases in the DNS Resolver) checked.
I'm seeing the same behavior this morning after updating to the latest snapshot. I turned off the DHCP registration stuff in DNS Resolver and it starts up just fine.
-
Hi
Thu Nov 20 00:23:34 CST 2014 build i can enable DHCP Registration.
-
Today with build Fri Nov 21 01:58:53 CST 2014 I'm getting again 'fatal error: Could not read config file: /unbound.conf' with DHCP Registration checked.
-
Today with build Fri Nov 21 01:58:53 CST 2014 I'm getting again 'fatal error: Could not read config file: /unbound.conf' with DHCP Registration checked.
Can't seem to replicate that. How is your Unbound configured?
-
-
To me, it gives the error attached if I try to start resolver with "Register DHCP leases in the DNS Resolver" set.
2.2-BETA (amd64)
built on Fri Nov 21 08:16:06 CST 2014
FreeBSD 10.1-RELEASE
-
@cmb:
Today with build Fri Nov 21 01:58:53 CST 2014 I'm getting again 'fatal error: Could not read config file: /unbound.conf' with DHCP Registration checked.
Can't seem to replicate that. How is your Unbound configured?
With version '2.2-BETA (amd64) built on Fri Nov 21 08:16:06 CST 2014' unbound started directly after upgrade. After another reboot it didn't start with DHCP Registration ('Register DHCP leases in the DNS Resolver') on.
-
What's in your resolver log? Re: config, how are all the settings under Services>DNS Resolver configured?
-
resolver.log
Nov 21 23:04:26 unbound: [6842:0] fatal error: Could not read config file: /unbound.conf Nov 21 23:04:26 unbound: [6842:0] info: ignored infra-lame-ttl: 900 (option removed, use infra-host-ttl) Nov 21 23:04:26 unbound: [6842:0] notice: Restart of unbound 1.4.22. Nov 21 23:04:26 unbound: [6842:0] debug: cache memory msg=66072 rrset=66072 infra=2600 val=66280 Nov 21 23:04:26 unbound: [6842:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out Nov 21 23:04:26 unbound: [6842:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0 Nov 21 23:04:26 unbound: [6842:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch Nov 21 23:04:26 unbound: [6842:0] debug: cache memory msg=66072 rrset=66072 infra=2600 val=66280 Nov 21 23:04:26 unbound: [6842:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out Nov 21 23:04:26 unbound: [6842:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0 Nov 21 23:04:26 unbound: [6842:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch Nov 21 23:04:26 unbound: [6842:0] info: service stopped (unbound 1.4.22). Nov 21 23:04:26 unbound: [6842:0] debug: caught signal SIGHUP Nov 21 23:04:26 unbound: [6842:1] debug: cache memory msg=66072 rrset=66072 infra=2600 val=66280 Nov 21 23:04:26 unbound: [6842:0] info: start of service (unbound 1.4.22). Nov 21 23:04:26 unbound: [6842:0] debug: cache memory msg=66072 rrset=66072 infra=2600 val=66280 Nov 21 23:04:26 unbound: [6842:0] debug: target fetch policy for level 4 is 0 Nov 21 23:04:26 unbound: [6842:0] debug: target fetch policy for level 3 is 0 Nov 21 23:04:26 unbound: [6842:0] debug: target fetch policy for level 2 is 1 Nov 21 23:04:26 unbound: [6842:0] debug: target fetch policy for level 1 is 2 Nov 21 23:04:26 unbound: [6842:0] debug: target fetch policy for level 0 is 3 Nov 21 23:04:26 unbound: [6842:0] notice: init module 1: iterator Nov 21 23:04:26 unbound: [6842:0] notice: init module 0: validator Nov 21 23:04:26 unbound: [6842:0] debug: module config: "validator iterator" Nov 21 23:04:26 unbound: [6842:0] debug: duplicate acl address ignored. Nov 21 23:04:26 unbound: [6842:0] debug: drop user privileges, run as unbound Nov 21 23:04:26 unbound: [6842:0] debug: chroot to /var/unbound Nov 21 23:04:26 unbound: [6842:0] debug: chdir to /var/unbound Nov 21 23:04:25 unbound: [87880:0] debug: switching log to stderr Nov 21 23:04:25 unbound: [87880:0] debug: cache memory msg=66072 rrset=66072 infra=288782 val=149925 Nov 21 23:04:25 unbound: [87880:0] info: 1.000000 2.000000 7 Nov 21 23:04:25 unbound: [87880:0] info: 0.524288 1.000000 21 Nov 21 23:04:25 unbound: [87880:0] info: 0.262144 0.524288 62 Nov 21 23:04:25 unbound: [87880:0] info: 0.131072 0.262144 100 Nov 21 23:04:25 unbound: [87880:0] info: 0.065536 0.131072 50 Nov 21 23:04:25 unbound: [87880:0] info: 0.032768 0.065536 83 Nov 21 23:04:25 unbound: [87880:0] info: 0.016384 0.032768 176 Nov 21 23:04:25 unbound: [87880:0] info: 0.008192 0.016384 27 Nov 21 23:04:25 unbound: [87880:0] info: 0.004096 0.008192 1 Nov 21 23:04:25 unbound: [87880:0] info: 0.000000 0.000001 37 Nov 21 23:04:25 unbound: [87880:0] info: lower(secs) upper(secs) recursions Nov 21 23:04:25 unbound: [87880:0] info: [25%]=0.0234589 median[50%]=0.0489546 [75%]=0.195297 Nov 21 23:04:25 unbound: [87880:0] info: histogram of recursion processing times Nov 21 23:04:25 unbound: [87880:0] info: average recursion processing time 0.139959 sec Nov 21 23:04:25 unbound: [87880:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 564 recursion replies sent, 0 replies dropped, 0 states jostled out Nov 21 23:04:25 unbound: [87880:0] info: server stats for thread 1: requestlist max 14 avg 0.603774 exceeded 0 jostled 0 Nov 21 23:04:25 unbound: [87880:0] info: server stats for thread 1: 1688 queries, 1124 answers from cache, 564 recursions, 178 prefetch Nov 21 23:04:25 unbound: [87880:0] debug: cache memory msg=66072 rrset=66072 infra=288782 val=149925 Nov 21 23:04:25 unbound: [87880:0] info: 1.000000 2.000000 1 Nov 21 23:04:25 unbound: [87880:0] info: 0.524288 1.000000 14 Nov 21 23:04:25 unbound: [87880:0] info: 0.262144 0.524288 30 Nov 21 23:04:25 unbound: [87880:0] info: 0.131072 0.262144 42 Nov 21 23:04:25 unbound: [87880:0] info: 0.065536 0.131072 28 Nov 21 23:04:25 unbound: [87880:0] info: 0.032768 0.065536 39 Nov 21 23:04:25 unbound: [87880:0] info: 0.016384 0.032768 52 Nov 21 23:04:25 unbound: [87880:0] info: 0.008192 0.016384 13 Nov 21 23:04:25 unbound: [87880:0] info: 0.004096 0.008192 1 Nov 21 23:04:25 unbound: [87880:0] info: 0.000000 0.000001 18 Nov 21 23:04:25 unbound: [87880:0] info: lower(secs) upper(secs) recursions Nov 21 23:04:25 unbound: [87880:0] info: [25%]=0.0250486 median[50%]=0.0621752 [75%]=0.216893 Nov 21 23:04:25 unbound: [87880:0] info: histogram of recursion processing times Nov 21 23:04:25 unbound: [87880:0] info: average recursion processing time 0.147787 sec Nov 21 23:04:25 unbound: [87880:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 238 recursion replies sent, 0 replies dropped, 0 states jostled out Nov 21 23:04:25 unbound: [87880:0] info: server stats for thread 0: requestlist max 40 avg 3.168 exceeded 0 jostled 0 Nov 21 23:04:25 unbound: [87880:0] info: server stats for thread 0: 548 queries, 310 answers from cache, 238 recursions, 12 prefetch Nov 21 23:04:25 unbound: [87880:0] info: service stopped (unbound 1.4.22). Nov 21 23:04:25 unbound: [87880:0] debug: caught signal SIGTERM Nov 21 23:04:23 unbound: [87880:1] debug: cache memory msg=418824 rrset=714129 infra=288782 val=149925 Nov 21 23:04:23 unbound: [87880:1] info: validator operate: query cl4appf.com. A IN Nov 21 23:04:23 unbound: [87880:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Nov 21 23:04:23 unbound: [87880:1] info: finishing processing for cl4appf.com. A IN Nov 21 23:04:23 unbound: [87880:1] info: query response was ANSWER Nov 21 23:04:23 unbound: [87880:1] info: reply from <cl4appf.com.> 78.140.168.56#53 Nov 21 23:04:23 unbound: [87880:1] info: response for cl4appf.com. A IN Nov 21 23:04:23 unbound: [87880:1] info: sanitize: storing potential poison RRset: ns2.dcrmt.net. A IN Nov 21 23:04:23 unbound: [87880:1] info: sanitize: storing potential poison RRset: ns1.dcrmt.net. A IN Nov 21 23:04:23 unbound: [87880:1] info: iterator operate: query cl4appf.com. A IN Nov 21 23:04:23 unbound: [87880:1] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Nov 21 23:04:23 unbound: [87880:1] debug: cache memory msg=418824 rrset=714129 infra=288782 val=149925 Nov 21 23:04:23 unbound: [87880:1] info: Verified that unsigned response is INSECURE Nov 21 23:04:23 unbound: [87880:1] info: validator operate: query cl4appf.com. AAAA IN Nov 21 23:04:23 unbound: [87880:1] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass Nov 21 23:04:23 unbound: [87880:1] info: NSEC3s for the referral proved no DS. Nov 21 23:04:23 unbound: [87880:1] info: validator operate: query cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Nov 21 23:04:23 unbound: [87880:1] info: finishing processing for cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] info: query response was nodata ANSWER Nov 21 23:04:23 unbound: [87880:1] info: reply from <com.> 2001:503:a83e::2:30#53 Nov 21 23:04:23 unbound: [87880:1] info: response for cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] info: iterator operate: query cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Nov 21 23:04:23 unbound: [87880:1] debug: cache memory msg=418824 rrset=714129 infra=288782 val=149925 Nov 21 23:04:23 unbound: [87880:1] debug: sending to target: <com.> 2001:503:a83e::2:30#53 Nov 21 23:04:23 unbound: [87880:1] info: sending query: cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] info: processQueryTargets: cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] info: resolving (init part 3): cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] info: resolving (init part 2): cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] info: resolving cl4appf.com. DS IN Nov 21 23:04:23 unbound: [87880:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Nov 21 23:04:23 unbound: [87880:1] info: validator operate: query cl4appf.com. DS IN</com.></com.></cl4appf.com.>
system.log
Nov 21 23:04:26 zh01-rt02 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process. Nov 21 23:04:27 zh01-rt02 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process. Nov 21 23:04:29 zh01-rt02 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process. Nov 21 23:04:29 zh01-rt02 dhcpleases: kqueue error: unkown Nov 21 23:04:29 zh01-rt02 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process.
Image with options is attached.
![Screenshot 2014-11-21 23.10.46.gif](/public/imported_attachments/1/Screenshot 2014-11-21 23.10.46.gif)
![Screenshot 2014-11-21 23.10.46.gif_thumb](/public/imported_attachments/1/Screenshot 2014-11-21 23.10.46.gif_thumb) -
2.2-BETA (amd64)
built on Sat Nov 22 01:52:19 CST 2014
FreeBSD 10.1-RELEASEAfter today's upgrade Resolver "went to sleep", had to switch for DNS Forwarder.
Oct 28 14:12:42 unbound: [23277:3] notice: sendto failed: No buffer space available
I know, the date is wrong.
-
Today with build Fri Nov 21 01:58:53 CST 2014 I'm getting again 'fatal error: Could not read config file: /unbound.conf' with DHCP Registration checked.
That seems to be fixed after merging a pull request from wagonza yesterday. I found one system where I could replicate that, and after that change, I no longer could. There is a bug ticket on that issue. https://redmine.pfsense.org/issues/4036
Others who could replicate that, are you seeing it on snapshots from the 23rd or newer?
-
@cmb:
That seems to be fixed after merging a pull request from wagonza yesterday. I found one system where I could replicate that, and after that change, I no longer could. There is a bug ticket on that issue. https://redmine.pfsense.org/issues/4036
Others who could replicate that, are you seeing it on snapshots from the 23rd or newer?
The latest snapshot I can get is 'Sat Nov 22 01:52:19 CST 2014'.
-
@cmb:
That seems to be fixed after merging a pull request from wagonza yesterday. I found one system where I could replicate that, and after that change, I no longer could. There is a bug ticket on that issue. https://redmine.pfsense.org/issues/4036
Others who could replicate that, are you seeing it on snapshots from the 23rd or newer?
With snapshot 'Mon Nov 24 02:33:34 CST 2014' my unbound problem is gone.
Thank You!
-
Seems solved. It starts normally now.
2.2-BETA (amd64)
built on Mon Nov 24 02:33:34 CST 2014
FreeBSD 10.1-RELEASE -
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 -
well…. spoke to soon. Can't enable "Register DHCP leases in the DNS Resolver". It refuses to start again.
and logs what?
-
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: validatorBUT, 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.
-
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.
-