Unbound package - Logging

markn62

Hello all,
I'm not finding any info on unbound logging searching the web and this forum. Although unbound has ran just fine since first installed I've only got it to log to the Package Log a couple times by changing the logging settings both by GUI and by adder commands. Now I can't get that, just get "log file started".

Any suggestions how to get 1 hr interval logging to work? The last portion of unbound.conf follows;

Domain overrides

Unbound Custom options

use-syslog: no
logfile: /var/log/unbound.log
verbosity: 1
statistics-interval: 3600
statistics-cumulative: yes
num-threads: 1
rrset-cache-size: 16m
num-threads: 1
msg-cache-slabs: 1
rrset-cache-slabs: 1
infra-cache-slabs: 1
key-cache-slabs: 1
outgoing-range: 800
so-rcvbuf: 1m
so-sndbuf: 1m
log-time-ascii: yes
do-ip4: yes
do-ip6: no
do-udp: yes
do-tcp: yes
forward-zone:
name: "."
forward-addr: 8.8.8.8
forward-addr: 8.8.4.4
forward-addr: 4.2.2.1

wagonza

All those settings are your own custom options - why you setting that? Most (if not all) are configurable through the webGUI.

Unbound logs to syslog and sylog is logging to a clog file /var/log/unbound.log.

markn62

Yes, I know some of them are redundant in the GUI but also some are not like outgoing range, send/rec buffers, forward-addr. Regardless anything added to the custom area just overrides what the GUI placed earlier in the unbound.conf file. I could remove all custom entries and still no logging. Worked it 10 ways to Sunday.

I'm hoping someone has ideas on how to debug. I would uninstall/reinstall the package but the router is in production and would have to be swapped out with backup router at 3 A.M. for deeper work.

markn62

<bump>Built a new dual-core AMD64 box, 8G ram, SSD, etc. Fresh install of AMD 64bit liveCD to SSD. Copied xml from "in service" box to new box. Package logs still don't work. Suppose I could try resetting factory defaults but doubt that will touch packages, can anyone say? I would have checked functionality before copying my xml but the install failed to remove/reinstall unbound package because removing unbound broke internet connection so the packages couldn't be fetched.

Seems like I'm the only one having this issue.</bump>

wagonza

Is this on a full install?

What happens if you specify a different log file eg /var/log/myunbound.log ? (try touch it before in case it does not get created on unbound startup).

For my curiosity what is the problem with the package's logging?

markn62

This is a full install on ver 2.0.3, 32-bit. Doesn't work on 2.1RC1 64-bit either. Have/had use-syslog: no in unbound script. Modified script from logfile: /var/log/unbound.log to logfile: /var/log/ub.log. Restarted and no ub.log was created at startup or after the 5 min script interval. Not sure what you mean by touch it. Permissions?

doktornotor

The log exists perfectly fine here without doing anything. I'd suggest to remove the custom configuration altogether, uninstall and reinstall the package. All the custom stuff is vastly redundant and extremely error-prone.

markn62

Been running unbound stand-alone for a year before spinning up PfSense a few months ago so well familar with unbound syntax and scripts unless PfSense handles scripts differently. Never had any issues with my stand-alone install on a separate Win32 box. I use scripted items because not all of the "essential" arguments are in the PfSense Unbound package GUI such as;

outgoing range:
msg-cache-slabs:
rrset-cache-slabs:
infra-cache-slabs:
key-cache-slabs:
so-rcvbuf:
so-sndbuf:

Some how Unbound determined that I want a value of 8192 for outgoing range which is way too high for my 4M ram single core x86 Celeron. Suppose to be about 800 or unbound is very unstable. And the slabs were set by the package to be 4 instead of 1 which is also high. Can't set the sndbuf or rcvbuf value in the GUI either. So added script arguments are essential in my temporary "in service" box.

I'll try zero scripts on the new 64-bit box, not yet in service. Then reinstall the package if necessary and report my findings.
Thanks.

doktornotor

@markn62:

Been running unbound stand-alone for a year before spinning up PfSense a few months ago so well familar with unbound syntax and scripts unless PfSense handles scripts differently.

I seriously mean it's extremely error prone. E.g.:


server:; local-zone: "0.0.10.in-addr.arpa." transparent;
server:; local-zone: "88.168.192.in-addr.arpa." transparent;
server:; local-zone: "20.168.192.in-addr.arpa." transparent

works while putting


local-zone: "0.0.10.in-addr.arpa." transparent;
local-zone: "88.168.192.in-addr.arpa." transparent;
local-zone: "20.168.192.in-addr.arpa." transparent

in custom configuration results in unbound not even starting.

markn62

You were right dok. On the AMD64 I trimmed the custom script down, as listed below, so there was no overlap with GUI settings. I imagine it was choking on one item in the script that isn't like the Win version but no sense in flushing it out. Package log is working again, yay!

outgoing-range: 800;
so-rcvbuf: 1m;
so-sndbuf: 1m;
do-ip6: no;
forward-zone: ;name: ".";
forward-addr: 8.8.8.8;
forward-addr: 8.8.4.4;
forward-addr: 4.2.2.1

doktornotor

I'm much more familiar with BIND, so… maybe some of the devs can comment on the issues, however just reading the unbound docs it appears the conf file syntax is rather unfortunate, with colon used in a ambiguous way (i.e., "Some attributes have attributes inside them.") causing the whole server, remote-control, stub-zone, forward-zone etc. mess.

markn62

Thanks for your help Dok…

markn62

Just got bit by Unbound again. Got a send buffer overrun so I thought I would bump up an existing custom entry of so-sndbuf from 1M to 4m. Even though unbound-checkconf said my script was good it apparently wasn't. The Unbound service refused to start with log errors saying it couldn't communicate with the public recursive servers. Perhaps the FreeBsd buffer would have to be bumped up in size to avoid this problem, not sure. But as Dok says, step lightly adding any custom scripts to Unbound, one at a time, test, repeat.

markn62

Traffic is increasing and I now get regular occurances of the error; "unbound: [91695:0] notice: sendto failed: No buffer space available" So now I NEED "so-sndbuf: 4m" in the script but the Pfsense Unbound package won't accept it as part of a custom script.

Any other method to introduce the script line, and sticky, such that it doesn't stop the Unbound service? System tunables maybe?

markn62

It appears the so-sndbuf option was added in Unbound version 1.4.8. The PfSense Unbound package is 1.4.20_8. What gives?

Unbound 1.4.8
Download: unbound-1.4.8.tar.gz SHA1 checksum: 557a9c10de9a83f88cd7c66d44488f1cb65de4fa SHA256 checksum: 5bf4060d2e778a1268498f4937583726d1d36909d7f40900ee31a722a64d506f Date: 24 January, 2011

Features

harden-below-nxdomain config option, default off (because very old software may be incompatible). We could enable it by default in the future. From draft-vixie-dnsext-resimprove-00.
typetransparent localzone: does not block other RR types.
so-sndbuf option for very busy servers, a bit like so-rcvbuf.

Re: http://unbound.net/download.html

wagonza

I have added the option so-sndbuf to the latest package update. It also updates Unbound to v1.4.21 - just waiting on the package to be built.
It will automatically determine the size for the 2 buffers from the sysctl value 'kern.ipc.maxsockbuf'. This is defaulted to 4MB. So you can change that value to have these buffers adjusted accordingly.

markn62

So Wag,
Why are band-aids being added to the unbound package? It's already dumbed down too much as it is. Are you really suggesting that the kern.ipc.maxsockbuf will, in the future release, be used to set the values of outgoing-num-tcp and incoming-num-tcp? What then if maxsockbuf is set to zero so the incoming and outgoing buffers are also set to zero so that only UDP is responded too by Unbound? This is what the Unbound, Advanced, web configurator notes suggest. Does this mean that there will be no UDP buffering with maxsockbuf set to zero? Perhaps UDP never gets buffered anyway and I need the education.

We are already inquiring what packages we want on the wishlist. How bout we get the existing packages working correctly first. For starters, how bout fixing the custom scripts section, built into the WebConfigurator, to modify Unbound settings without causing the service to not start. And how bout http://forum.pfsense.org/index.php?topic=68804.0 describing how the outgoing-num-tcp and incoming-num-tcp GUI settings don't change the unbound.conf file.

How bout more attention be given these minor fixes working before moving on to greener pastures. Prior to PfSense I ran a stand-alone unbound package that didn't have any issues. All script commands worked and never reported any errors. The package version appears to be a stripped down Vega, generating regular errors to the unbound.log. You get it "as is" without much ability to tweak out errors after someone in their infinite wisdom thought the same size fits all.

markn62

To boil down this issue, I find if any parameter is in the unbound package configuration you cannot modify it with the custom script. So to solve this thread, the question that needs to be answered is, "why won't the WebGui allow script entries to modify what is currently in the unbound config? To make matters worse, some of the GUI field values won't propogate to the unbound.conf. So there are many values you can't change by script or GUI.

So does anyone know where the default config is that the unbound package uses as a starting point and is it editable? Perhaps this way I can set some unbound parameters as a way to work around these unreasonable limitations.

markn62

Any update on the release of Unbound v1.4.21 that modifies how so-sndbuf is handled? Still seeing ver 1.4.21 on the ackages list, however it installs as 1.4.20 so presumably no fix yet.

wagonza

so after all that moaning, is it now working as expected?
Of course patches are accepted and bugs are logged on redmine.pfsense.org