[tor-relays] How many threads needed for unbound at a fast relay?

Toralf Förster toralf.foerster at gmx.de
Sat Sep 5 17:57:23 UTC 2020


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


-- 
Toralf

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 228 bytes
Desc: OpenPGP digital signature
URL: <http://lists.torproject.org/pipermail/tor-relays/attachments/20200905/32b7529f/attachment.sig>


More information about the tor-relays mailing list