Unbound package - Logging



  • 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



  • 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.



  • 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.



  • <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>



  • 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?



  • 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?


  • Banned

    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.



  • 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.


  • Banned

    @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.



  • 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


  • Banned

    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.



  • Thanks for your help Dok…



  • 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.



  • 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?



  • 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



  • 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.



  • 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.



  • 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.



  • 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.



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



  • Unbound doesn't seem as stable as a package.  The package doesn't work on a 32-bit test box but works for the most part on a 64-bit production box if I ignore the unbound service restarts that happen at least once a day.  To better understand why they're so different, I thought making comparisons between the unbound package and the stand-alone unbound service would be helpful in reaching a solution.  It's called moaning now?

    
    2014-01-26 06:37:53	Daemon.Info	192.168.2.1	Jan 26 06:37:53 unbound: [63663:0] info: service stopped (unbound 1.4.20).
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: server stats for thread 0: 649 queries, 232 answers from cache, 417 recursions, 16 prefetch
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: server stats for thread 0: requestlist max 11 avg 1.31409 exceeded 0 jostled 0
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: average recursion processing time 0.082272 sec
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: histogram of recursion processing times
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: [25%]=0.025671 median[50%]=0.0479013 [75%]=0.0966887
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: lower(secs) upper(secs) recursions
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.000000    0.000001 46
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.001024    0.002048 1
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.016384    0.032768 101
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.032768    0.065536 131
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.065536    0.131072 71
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.131072    0.262144 37
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.262144    0.524288 25
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.524288    1.000000 5
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: server stats for thread 1: 139 queries, 48 answers from cache, 91 recursions, 4 prefetch
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: server stats for thread 1: requestlist max 5 avg 0.410526 exceeded 0 jostled 0
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: average recursion processing time 0.094866 sec
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: histogram of recursion processing times
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: [25%]=0.0297405 median[50%]=0.0511379 [75%]=0.101581
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info: lower(secs) upper(secs) recursions
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.000000    0.000001 4
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.016384    0.032768 23
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.032768    0.065536 33
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.065536    0.131072 15
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.131072    0.262144 6
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.262144    0.524288 9
    2014-01-26 06:37:54	Daemon.Info	192.168.2.1	Jan 26 06:37:54 unbound: [63663:0] info:    0.524288    1.000000 1
    2014-01-26 06:38:01	User.Error	192.168.2.1	Jan 26 06:38:01 php: servicewatchdog_cron.php: Service Watchdog detected service unbound stopped. Restarting unbound (Unbound is a validating, recursive, and caching DN...)
    
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: service stopped (unbound 1.4.20).
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: server stats for thread 0: 8980 queries, 3591 answers from cache, 5389 recursions, 285 prefetch
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: server stats for thread 0: requestlist max 13 avg 0.853366 exceeded 0 jostled 0
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: average recursion processing time 0.395473 sec
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: histogram of recursion processing times
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: [25%]=0.0220116 median[50%]=0.0314482 [75%]=0.0603143
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: lower(secs) upper(secs) recursions
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.000000    0.000001 504
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.000256    0.000512 1
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.000512    0.001024 2
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.001024    0.002048 3
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.002048    0.004096 2
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.004096    0.008192 9
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.008192    0.016384 23
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.016384    0.032768 2340
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.032768    0.065536 1379
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.065536    0.131072 517
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.131072    0.262144 358
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.262144    0.524288 169
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.524288    1.000000 34
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    1.000000    2.000000 6
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    2.000000    4.000000 5
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    4.000000    8.000000 1
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:   16.000000   32.000000 4
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:   32.000000   64.000000 31
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:   64.000000  128.000000 3
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: server stats for thread 1: 4942 queries, 1892 answers from cache, 3050 recursions, 170 prefetch
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: server stats for thread 1: requestlist max 7 avg 0.408696 exceeded 0 jostled 0
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: average recursion processing time 0.398189 sec
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: histogram of recursion processing times
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: [25%]=0.0222939 median[50%]=0.031751 [75%]=0.0616897
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: lower(secs) upper(secs) recursions
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.000000    0.000001 277
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.001024    0.002048 1
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.002048    0.004096 1
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.004096    0.008192 2
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.008192    0.016384 5
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.016384    0.032768 1321
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.032768    0.065536 771
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.065536    0.131072 301
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.131072    0.262144 230
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.262144    0.524288 95
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    0.524288    1.000000 19
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    1.000000    2.000000 4
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:    2.000000    4.000000 1
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:   16.000000   32.000000 3
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info:   32.000000   64.000000 19
    2014-01-27 03:31:00	Daemon.Notice	pfsense	Jan 27 03:31:00 unbound: [2025:0] notice: Restart of unbound 1.4.20.
    2014-01-27 03:31:00	Daemon.Warning	pfsense	Jan 27 03:31:00 unbound: [2025:0] warning: setrlimit: Operation not permitted
    2014-01-27 03:31:00	Daemon.Warning	pfsense	Jan 27 03:31:00 unbound: [2025:0] warning: cannot increase max open fds from 11095 to 16458
    2014-01-27 03:31:00	Daemon.Warning	pfsense	Jan 27 03:31:00 unbound: [2025:0] warning: continuing with less udp ports: 5512
    2014-01-27 03:31:00	Daemon.Warning	pfsense	Jan 27 03:31:00 unbound: [2025:0] warning: increase ulimit or decrease threads, ports in config to remove this warning
    2014-01-27 03:31:00	Daemon.Notice	pfsense	Jan 27 03:31:00 unbound: [2025:0] notice: init module 0: validator
    2014-01-27 03:31:00	Daemon.Notice	pfsense	Jan 27 03:31:00 unbound: [2025:0] notice: init module 1: iterator
    2014-01-27 03:31:00	Daemon.Info	pfsense	Jan 27 03:31:00 unbound: [2025:0] info: start of service (unbound 1.4.20).
    
    2014-01-27 11:32:13	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: service stopped (unbound 1.4.20).
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: server stats for thread 0: 68 queries, 20 answers from cache, 48 recursions, 4 prefetch
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: server stats for thread 0: requestlist max 2 avg 0.173077 exceeded 0 jostled 0
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: average recursion processing time 0.067424 sec
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: histogram of recursion processing times
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: [25%]=0.0227556 median[50%]=0.0352886 [75%]=0.065536
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: lower(secs) upper(secs) recursions
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.000000    0.000001 5
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.016384    0.032768 18
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.032768    0.065536 13
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.065536    0.131072 5
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.131072    0.262144 5
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.262144    0.524288 2
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: server stats for thread 1: 664 queries, 209 answers from cache, 455 recursions, 22 prefetch
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: server stats for thread 1: requestlist max 7 avg 1.01258 exceeded 0 jostled 0
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: average recursion processing time 0.074148 sec
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: histogram of recursion processing times
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: [25%]=0.0253615 median[50%]=0.0431843 [75%]=0.0786432
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info: lower(secs) upper(secs) recursions
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.000000    0.000001 32
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.002048    0.004096 1
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.008192    0.016384 1
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.016384    0.032768 146
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.032768    0.065536 151
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.065536    0.131072 55
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.131072    0.262144 45
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.262144    0.524288 20
    2014-01-27 11:32:14	Daemon.Info	pfsense	Jan 27 11:32:14 unbound: [2025:0] info:    0.524288    1.000000 5
    2014-01-27 11:32:16	Daemon.Notice	pfsense	Jan 27 11:32:16 unbound: [95251:0] notice: init module 0: validator
    2014-01-27 11:32:16	Daemon.Notice	pfsense	Jan 27 11:32:16 unbound: [95251:0] notice: init module 1: iterator
    2014-01-27 11:32:16	Daemon.Info	pfsense	Jan 27 11:32:16 unbound: [95251:0] info: start of service (unbound 1.4.20).
    
    


  • It seems too work for a lot of other users, granted they may not be configuring all the settings and fine tuning the knobs like your installation.

    Its called 'moaning' because you go on a tangent about how its dumbed down, the package assumes too much by pre-configuring certain settings, how some settings don't work and getting existing packages working first before embarking on developing new packages. But yet provide nothing useful in terms of bugs logged nor patches.

    Thanks though for the information that you have provided so far in this thread. As for the pre-configured settings which ones are incorrect? They were done right in the beginning of the package so some adjustments may be needed.



  • Sorry for using the term "dumbed down" rather than "simplified for new users", I suppose that sounds better.  I would log bugs and patches if I understood the process.  I've been using PfSense for about 5 months now so I'm a relatively new user.

    On this issue I initially suggested that all native unbound commands be recognized by the GUI custom entry box such that they override the GUI setttings.  Or if this is unacceptable, at least allow custom commands that are not configurable via the GUI.  I could test every unbound command to see if it keeps the service from starting but that would take about a day.  I'm sure someone more familiar could generate a list in a few minutes.

    The bigger question is, "what's the goal"?  What can and can't be done with the unbound package script.  So far I'm seeing more interest in using command parameters to generate other command parameters.  In other words, a continuation to keep it simple and automated, rather than improving the ability to troubleshoot performance issues should they arise.  Maybe you can explain why the native commands weren't included in the package.  Is it just the time and effort to provide features that may get little use?

    As someone who had been using a stand-alone unbound service with only a script, surely you would expect some moaning when most of the script settings were rejected by PfSense.  It would have been nice to drop in a well tested and stable script rather than use the automated package that restarts now and then.  I may go back to a stand-alone service if I can't resolve the restarts.

    Are there other 64-bit users seeing their unbound package perform unattended restarts?  No idea how to troubleshoot this especially with many of the commands unrecognized.  Fortunately the service restarts fairly quick so it doesn't seem to cause much disruption.  However with each occurance the cache is cleared and has to begin rebuilding when the service starts making the package less effective.  I don't save the cache because of the SSD and it adds too much time to a PfSense reboot.


Log in to reply