[Pdns-users] Recursor 3.4-pre : rec_control get cache-bytes taking about 5sec after few hours running

Fri Jan 20 17:09:18 UTC 2012

Hi David,

We are aware of this. 3.4 will have a fix for this. Thank you for your very complete report!

Peter
-- 
Sent from my Android phone with K-9 Mail. Please excuse my brevity.

"GAVARRET, David" <david.gavarret at sfr.com> wrote:

Hello,

we have just upgraded some more production servers with version 3.4-pre of pdns_recursor.
Over time (in our case, after about 18 hours), reading of statistics via the command "rec_control get-all" takes more and more time, up to 5 seconds. These 5 seconds also seem to be a timeout limit, and so when it is reached, the command fails with the following error :
" Fatal: Unable to receive message over control channel: Success " 

In the log file, the message is a bit longer :
" Error dealing with control socket request: Unable to send message over control channel '/var/run/powerdns//lsockcaf2V2': No such file or directory "

With version 3.3, statistics are always returned within 10 ms, even after hundreds of days running.
The settings are identical on the servers running 3.3 and servers running 3.4 version. The CPU and load average are also quite the same.

It seems that the "cache-bytes" statistic is the one taking so much time. Here is the measure time for getting each statistic with unitary command "rec_control get" :

$ for id in `sudo rec_control --socket-dir=/var/run/powerdns/ get-all | cut -f 1`; do echo "$id : " ; time sudo rec_control --socket-dir=/var/run/powerdns/ get $id ; done
all-outqueries :
41460979

real 0m0.007s
user 0m0.000s
sys 0m0.000s
dlg-only-drops :
0

real 0m0.006s
user 0m0.004s
sys 0m0.000s
dont-outqueries :
151500

real 0m0.005s
user 0m0.004s
sys 0m0.000s
max-mthread-stack :
36264

real 0m0.006s
user 0m0.004s
sys 0m0.004s
outgoing-timeouts :
1776957

real 0m0.005s
user 0m0.004s
sys 0m0.000s
tcp-outqueries :
49713

real 0m0.006s
user 0m0.004s
sys 0m0.004s
throttled-out :
418136

real 0m0.006s
user 0m0.004s
sys 0m0.000s
throttled-outqueries :
418136

real 0m0.006s
user 0m0.004s
sys 0m0.004s
unreachables :
226341

real 0m0.006s
user 0m0.004s
sys 0m0.000s
answers-slow :
899924

real 0m0.006s
user 0m0.004s
sys 0m0.004s
answers0-1 :
17180424

real 0m0.005s
user 0m0.004s
sys 0m0.000s
answers1-10 :
8097358

real 0m0.005s
user 0m0.004s
sys 0m0.004s
answers10-100 :
12337003

real 0m0.005s
user 0m0.004s
sys 0m0.004s
answers100-1000 :
8438958

real 0m0.006s
user 0m0.004s
sys 0m0.000s
case-mismatches :
0

real 0m0.005s
user 0m0.000s
sys 0m0.008s
chain-resends :
150757

real 0m0.005s
user 0m0.004s
sys 0m0.000s
client-parse-errors :
23334

real 0m0.006s
user 0m0.004s
sys 0m0.000s
edns-ping-matches :
0

real 0m0.006s
user 0m0.004s
sys 0m0.000s
edns-ping-mismatches :
0

real 0m0.006s
user 0m0.000s
sys 0m0.004s
ipv6-outqueries :
0

real 0m0.006s
user 0m0.000s
sys 0m0.004s
no-packet-error :
146612428

real 0m0.006s
user 0m0.000s
sys 0m0.004s
noedns-outqueries :
41506921

real 0m0.006s
user 0m0.000s
sys 0m0.008s
noerror-answers :
251917785

real 0m0.006s
user 0m0.004s
sys 0m0.000s
noping-outqueries :
0

real 0m0.006s
user 0m0.004s
sys 0m0.000s
nsset-invalidations :
84551

real 0m0.006s
user 0m0.000s
sys 0m0.008s
nxdomain-answers :
12293232

real 0m0.006s
user 0m0.000s
sys 0m0.008s
over-capacity-drops :
0

real 0m0.006s
user 0m0.004s
sys 0m0.000s
qa-latency :
26

real 0m0.006s
user 0m0.000s
sys 0m0.012s
questions :
267200911

real 0m0.006s
user 0m0.000s
sys 0m0.004s
resource-limits :
1

real 0m0.006s
user 0m0.000s
sys 0m0.008s
server-parse-errors :
2

real 0m0.006s
user 0m0.000s
sys 0m0.004s
servfail-answers :
2964254

real 0m0.006s
user 0m0.004s
sys 0m0.008s
spoof-prevents :
0

real 0m0.005s
user 0m0.004s
sys 0m0.000s
tcp-client-overflow :
0

real 0m0.006s
user 0m0.000s
sys 0m0.004s
tcp-questions :
11471

real 0m0.005s
user 0m0.004s
sys 0m0.004s
unauthorized-tcp :
0

real 0m0.006s
user 0m0.000s
sys 0m0.004s
unauthorized-udp :
0

real 0m0.005s
user 0m0.000s
sys 0m0.008s
unexpected-packets :
183889

real 0m0.006s
user 0m0.004s
sys 0m0.000s
cache-bytes :
1467740916

real 0m4.875s <<<<<<
user 0m0.000s
sys 0m0.008s
cache-entries :
12811541

real 0m0.009s
user 0m0.004s
sys 0m0.000s
cache-hits :
16743327

real 0m0.005s
user 0m0.004s
sys 0m0.008s
cache-misses :
30214506

real 0m0.006s
user 0m0.004s
sys 0m0.000s
concurrent-queries :
111

real 0m0.006s
user 0m0.004s
sys 0m0.000s
malloc-bytes :
0

real 0m0.006s
user 0m0.004s
sys 0m0.000s
negcache-entries :
1600262

real 0m0.007s
user 0m0.000s
sys 0m0.008s
nsspeeds-entries :
48068

real 0m0.006s
user 0m0.004s
sys 0m0.000s
packetcache-bytes :
53881659

real 0m0.119s
user 0m0.000s
sys 0m0.004s
packetcache-entries :
502387

real 0m0.006s
user 0m0.000s
sys 0m0.004s
packetcache-hits :
220244614

real 0m0.005s
user 0m0.000s
sys 0m0.004s
packetcache-misses :
46970437

real 0m0.006s
user 0m0.004s
sys 0m0.000s
sys-msec :
8463024

real 0m0.005s
user 0m0.000s
sys 0m0.004s
tcp-clients :
0

real 0m0.005s
user 0m0.004s
sys 0m0.000s
throttle-entries :
14957

real 0m0.005s
user 0m0.004s
sys 0m0.000s
uptime :
64397

real 0m0.005s
user 0m0.000s
sys 0m0.004s
user-msec :
20958557

real 0m0.005s
user 0m0.008s
sys 0m0.000s

Here is our recursor.conf file:

setuid=20100
setgid=20100
socket-owner=pdns
socket-group=pdns
socket-mode=770
socket-dir=/var/run/powerdns
allow-from-file=/etc/powerdns/dns-resolver-allow-from
forward-zones-file=/etc/powerdns/dns-resolver-forward-zones
local-address=...
max-cache-entries=16000000
stack-size=250000
threads=4
logging-facility=0
version-string=3.4-pre

I can provide any other information if needed,

Kind Regards,

-- 
David Gavarret
_____________________________________________

Pdns-users mailing list
Pdns-users at mailman.powerdns.com
http://mailman.powerdns.com/mailman/listinfo/pdns-users

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.powerdns.com/pipermail/pdns-users/attachments/20120120/a0ac66c1/attachment-0001.html>