Unbound logging

Unbound
1

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

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

dnscache can answer my questions ( not optimized for human reading :wink:
@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.

dnscache does:
@400000004ccac9371fe8442c query 55570 00000000000000000000ffff7f000001:8f33:9bbe 1 www.alleziele.de. < localhost is asking for ...
@400000004ccac9371fe8730c cached 1 www.alleziele.de. < cached answer

Can I configure unbound to give me the same informations as dnscache ???
Thanks !
Andreas

2

Hi Andreas,

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 :wink:
@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

3

Wouter,

maybe I have to learn new technics in debugging dns. Your hints are very helpfull.
Changing the dns software requires changed thinking, too...

Andreas

4

15.11.2010 12:38, W.C.A. Wijngaards wrote:
[]

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

Just in case, I'm not sure where the above come from....

Dsbl.org is dead, since summer 2008 if memory serves me right.

/mjt