[Unbound-users] unbound logging

Mon Nov 15 09:38:54 UTC 2010

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hi Andreas,

On 10/29/2010 03:42 PM, Andreas Schulze wrote:
> Hello,
> 
> I used dnscache for many years. Now I have little problems reading unbound logging.
> 
> 2010-10-29 15:09:52.908053500 [1288357792] unbound[13599:0] info: resolving <www.alleziele.de. A IN>
> 2010-10-29 15:09:52.920270500 [1288357792] unbound[13599:0] info: response for <www.alleziele.de. A IN>
> 2010-10-29 15:09:52.920273500 [1288357792] unbound[13599:0] info: reply from <de.> 81.91.164.5#53
> 2010-10-29 15:09:52.920274500 [1288357792] unbound[13599:0] info: query response was REFERRAL
> 
> 2010-10-29 15:09:52.939340500 [1288357792] unbound[13599:0] info: response for <www.alleziele.de. A IN>
> 2010-10-29 15:09:52.939342500 [1288357792] unbound[13599:0] info: reply from <alleziele.de.> 80.67.16.124#53
> 2010-10-29 15:09:52.939343500 [1288357792] unbound[13599:0] info: query response was ANSWER
> 
> The logging above can't answer two questions:
>  - which client asked Unbound ?
>  - what is the answer, the A record of www.alleziele.de. ?

If you enable higher verbosity then these details are printed as well.
By default it preserves privacy until loglevel 5 (prints source IP and
answer packets in dig-like format, as well as the resolve algorithm).

> Why Im intersted in this ?
> I usualy run dnscache/unbound supervised and put the logging into an circular buffer.
> In a case of trouble I my look what the resolver is doing...

Maybe what you want is a tcpdump port 53 ?
(with -p it does not set promiscuous mode).

> dnscache can answer my questions ( not optimized for human reading ;-)
> @400000004ccac920287b172c query 55408 00000000000000000000ffff7f000001:8f33:bf4c 1 www.alleziele.de.  < localhost is asking for ...
> @400000004ccac920279b9c3c rr 00000000000000000000ffffc0000235 3600 1 www.alleziele.de. 5043190d       < 192.0.2.53 answers "80.67.25.13"
> 
> also unbound gives me no information if any client asking for a *cached* information.

Well, print statements take a lot of time, and would slow down the cache
responses significantly.  tcpdump can tell you those queries and
answers.  (there are better DNS statistics packages, like dnstop,
dnsmon, ...)  Unbound does update the cache-response counter, which you
can get by querying unbound-control stats.

> Can I configure unbound to give me the same informations as dnscache ???

That sort of logging would become slow and bloat the code, there are
dedicated statistics packages that have all the bells and whistles.
There is already extensive statistics possible (
http://unbound.net/documentation/howto_statistics.html ) in unbound,
which is designed to not slow down unbound too much.  But that does not
log the individual queries, like you want here.

If you want to see 'what is unbound working on right now?' then
unbound-control dump_requestlist shows what thread0 is doing:
#   type cl name    seconds    module status
  0    A IN 40.220.127.86.list.dsbl.org. 36.086307 iterator wait for
192.0.2.1

Best regards,
   Wouter
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)
Comment: Using GnuPG with Fedora - http://enigmail.mozdev.org/

iEYEARECAAYFAkzg/64ACgkQkDLqNwOhpPhEIQCeI01XfuQvPQev30rwLXcch9kg
TZkAoKByVEaFAo1PIodhVJ1ZICaw8ib9
=K21G
-----END PGP SIGNATURE-----