On 8/24/20 8:52 PM, Tim Niemeyer wrote:
Hi Toralf
All F3 Netze relays together are using one unbound with 4 CPU Cores. Each consumes about ~20%. It's a Xeon(R) CPU E3-1230 V2 @ 3.30GHz (w/o Hyperthreading).
Ah thx, so I used 4 threads here for my 2 relaays and observed the pattern, that the first 2 threads have response times of > 512 sec, where the remainign 2 are more or less unused.
So it seems, # of relays + 1 would a good rule of thumb ?
Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: service stopped (unbound 1.10.1). Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 0: 69890 queries, 5166 answers from cache, 64724 recursions, 0 prefetch, 0 rejected by ip ratelimiting Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 0: requestlist max 83 avg 3.64886 exceeded 0 jostled 0 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: average recursion processing time 1.094680 sec Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: histogram of recursion processing times Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: [25%]=0.0198791 median[50%]=0.0497338 [75%]=0.125632 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: lower(secs) upper(secs) recursions Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000000 0.000001 865 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000256 0.000512 2 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000512 0.001024 98 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.001024 0.002048 111 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.002048 0.004096 423 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.004096 0.008192 4105 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.008192 0.016384 7897 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.016384 0.032768 12562 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.032768 0.065536 12165 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.065536 0.131072 11248 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.131072 0.262144 7076 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.262144 0.524288 3872 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.524288 1.000000 2002 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 1.000000 2.000000 805 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 2.000000 4.000000 489 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 4.000000 8.000000 152 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 8.000000 16.000000 171 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 16.000000 32.000000 293 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 32.000000 64.000000 128 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 64.000000 128.000000 170 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 128.000000 256.000000 27 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 256.000000 512.000000 57 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 512.000000 1024.000000 5 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 1: 21686 queries, 1834 answers from cache, 19852 recursions, 0 prefetch, 0 rejected by ip ratelimiting Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 1: requestlist max 85 avg 2.40293 exceeded 0 jostled 0 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: average recursion processing time 0.953444 sec Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: histogram of recursion processing times Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: [25%]=0.02107 median[50%]=0.0521733 [75%]=0.129936 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: lower(secs) upper(secs) recursions Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000000 0.000001 272 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000256 0.000512 3 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000512 0.001024 27 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.001024 0.002048 36 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.002048 0.004096 147 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.004096 0.008192 1085 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.008192 0.016384 2281 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.016384 0.032768 3888 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.032768 0.065536 3693 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.065536 0.131072 3518 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.131072 0.262144 2227 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.262144 0.524288 1246 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.524288 1.000000 697 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 1.000000 2.000000 285 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 2.000000 4.000000 164 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 4.000000 8.000000 36 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 8.000000 16.000000 58 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 16.000000 32.000000 115 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 32.000000 64.000000 24 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 64.000000 128.000000 30 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 128.000000 256.000000 3 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 256.000000 512.000000 13 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 512.000000 1024.000000 4 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 2: 276 queries, 221 answers from cache, 55 recursions, 0 prefetch, 0 rejected by ip ratelimiting Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 1: requestlist max 85 avg 2.40293 exceeded 0 jostled 0 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: average recursion processing time 0.953444 sec Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: histogram of recursion processing times Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: [25%]=0.02107 median[50%]=0.0521733 [75%]=0.129936 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: lower(secs) upper(secs) recursions Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000000 0.000001 272 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000256 0.000512 3 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000512 0.001024 27 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.001024 0.002048 36 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.002048 0.004096 147 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.004096 0.008192 1085 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.008192 0.016384 2281 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.016384 0.032768 3888 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.032768 0.065536 3693 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.065536 0.131072 3518 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.131072 0.262144 2227 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.262144 0.524288 1246 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.524288 1.000000 697 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 1.000000 2.000000 285 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 2.000000 4.000000 164 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 4.000000 8.000000 36 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 8.000000 16.000000 58 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 16.000000 32.000000 115 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 32.000000 64.000000 24 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 64.000000 128.000000 30 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 128.000000 256.000000 3 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 256.000000 512.000000 13 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 512.000000 1024.000000 4 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 2: 276 queries, 221 answers from cache, 55 recursions, 0 prefetch, 0 rejected by ip ratelimiting Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 2: requestlist max 1 avg 0.218182 exceeded 0 jostled 0 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: average recursion processing time 0.143181 sec Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: histogram of recursion processing times Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: [25%]=0.0160427 median[50%]=0.0628053 [75%]=0.181713 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: lower(secs) upper(secs) recursions Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000512 0.001024 4 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.002048 0.004096 3 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.004096 0.008192 1 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.008192 0.016384 6 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.016384 0.032768 8 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.032768 0.065536 6 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.065536 0.131072 9 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.131072 0.262144 11 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.262144 0.524288 4 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.524288 1.000000 2 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 1.000000 2.000000 1 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 3: 244 queries, 186 answers from cache, 58 recursions, 0 prefetch, 0 rejected by ip ratelimiting Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: server stats for thread 3: requestlist max 2 avg 0.344828 exceeded 0 jostled 0 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: average recursion processing time 0.094624 sec Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: histogram of recursion processing times Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: [25%]=0.01024 median[50%]=0.0268102 [75%]=0.126976 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: lower(secs) upper(secs) recursions Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000000 0.000001 1 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.000256 0.000512 5 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.002048 0.004096 4 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.004096 0.008192 2 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.008192 0.016384 10 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.016384 0.032768 11 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.032768 0.065536 3 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.065536 0.131072 8 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.131072 0.262144 7 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.262144 0.524288 6 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: 0.524288 1.000000 1 Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] notice: Restart of unbound 1.10.1. Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] notice: init module 0: validator Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] notice: init module 1: iterator Sep 5 19:53:32 mr-fox unbound[1954]: [1954:0] info: start of service (unbound 1.10.1).