[Unbound-users] unbound should probably manage other RLIMITs as well...
Greg A. Woods
woods at planix.ca
Tue Oct 27 22:35:48 UTC 2009
I have unbound-1.3.0 running on a pair of local hosts as my main
recursive resolvers on my local IPv4-only network, and sometimes one or
the other instance dies, this time I've got enough records to show that
it was claiming that it ran out of memory.
Syslog messages from just prior to, and during, the crash are appended
for completeness.
I have the following non-default memory-usage related settings:
num_threads: 1
rrset-cache-size: 256m
rrset-cache-slabs: 8
However note the soft datasize RLIMIT is just exactly 256m, through some
accident in how my system and kernel are configured, and this is of
course slightly too small for Unbound's current configuration:
# sysctl proc.25953
proc.25953.corename = %n.core
proc.25953.rlimit.cputime.soft = unlimited
proc.25953.rlimit.cputime.hard = unlimited
proc.25953.rlimit.filesize.soft = unlimited
proc.25953.rlimit.filesize.hard = unlimited
proc.25953.rlimit.datasize.soft = 268435456
proc.25953.rlimit.datasize.hard = 3221225472
proc.25953.rlimit.stacksize.soft = 67108864
proc.25953.rlimit.stacksize.hard = 67108864
proc.25953.rlimit.coredumpsize.soft = unlimited
proc.25953.rlimit.coredumpsize.hard = unlimited
proc.25953.rlimit.memoryuse.soft = 3920551936
proc.25953.rlimit.memoryuse.hard = 3920551936
proc.25953.rlimit.memorylocked.soft = 1306850645
proc.25953.rlimit.memorylocked.hard = 3920551936
proc.25953.rlimit.maxproc.soft = 2068
proc.25953.rlimit.maxproc.hard = 2068
proc.25953.rlimit.descriptors.soft = 6668
proc.25953.rlimit.descriptors.hard = 6668
proc.25953.rlimit.sbsize.soft = unlimited
proc.25953.rlimit.sbsize.hard = unlimited
proc.25953.stopfork = 0
proc.25953.stopexec = 0
proc.25953.stopexit = 0
So, this crash seems to have happening because the cache does finally
fill close to the specified limit, but since the process can't grow that
big, malloc() reports being out of memory and eventually Unbound gives
up and dies.
I think Unbound should probably try to manage other of its RLIMIT values
besides just the number of open files.
it could even try using getrusage(2) where available to discover initial
memory requirements at startup (though on many systems getrusage(2)
doesn't really provide enough useful information).
Oct 27 01:54:42 once unbound: [12262:0] info: server stats for thread 0: 450 queries, 56 answers from cache, 394 recursions
Oct 27 01:54:42 once unbound: [12262:0] info: server stats for thread 0: requestlist max 9 avg 4.35787 exceeded 0
Oct 27 01:54:42 once unbound: [12262:0] info: average recursion processing time 8.471841 sec
Oct 27 01:54:42 once unbound: [12262:0] info: histogram of recursion processing times
Oct 27 01:54:42 once unbound: [12262:0] info: [25%]=0.016384 median[50%]=0.00119156 [75%]=0.118561
Oct 27 01:54:42 once unbound: [12262:0] info: lower(secs) upper(secs) recursions
Oct 27 01:54:42 once unbound: [12262:0] info: 0.000000 0.000001 4
Oct 27 01:54:42 once unbound: [12262:0] info: 0.001024 0.002048 47
Oct 27 01:54:42 once unbound: [12262:0] info: 0.002048 0.004096 10
Oct 27 01:54:42 once unbound: [12262:0] info: 0.004096 0.008192 3
Oct 27 01:54:42 once unbound: [12262:0] info: 0.032768 0.065536 2
Oct 27 01:54:42 once unbound: [12262:0] info: 0.065536 0.131072 130
Oct 27 01:54:42 once unbound: [12262:0] info: 0.131072 0.262144 110
Oct 27 01:54:42 once unbound: [12262:0] info: 0.262144 0.524288 22
Oct 27 01:54:42 once unbound: [12262:0] info: 0.524288 1.000000 3
Oct 27 01:54:42 once unbound: [12262:0] info: 1.000000 2.000000 3
Oct 27 01:54:42 once unbound: [12262:0] info: 2.000000 4.000000 3
Oct 27 01:54:42 once unbound: [12262:0] info: 4.000000 8.000000 2
Oct 27 01:54:42 once unbound: [12262:0] info: 8.000000 16.000000 4
Oct 27 01:54:42 once unbound: [12262:0] info: 16.000000 32.000000 8
Oct 27 01:54:42 once unbound: [12262:0] info: 32.000000 64.000000 19
Oct 27 01:54:42 once unbound: [12262:0] info: 64.000000 128.000000 24
Oct 27 01:58:41 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 01:59:42 once unbound: [12262:0] info: server stats for thread 0: 552 queries, 126 answers from cache, 426 recursions
Oct 27 01:59:42 once unbound: [12262:0] info: server stats for thread 0: requestlist max 8 avg 3.6385 exceeded 0
Oct 27 01:59:42 once unbound: [12262:0] info: average recursion processing time 9.901999 sec
Oct 27 01:59:42 once unbound: [12262:0] info: histogram of recursion processing times
Oct 27 01:59:42 once unbound: [12262:0] info: [25%]=0.0156245 median[50%]=0.0624979 [75%]=0.114123
Oct 27 01:59:42 once unbound: [12262:0] info: lower(secs) upper(secs) recursions
Oct 27 01:59:42 once unbound: [12262:0] info: 0.000000 0.000001 2
Oct 27 01:59:42 once unbound: [12262:0] info: 0.001024 0.002048 56
Oct 27 01:59:42 once unbound: [12262:0] info: 0.002048 0.004096 4
Oct 27 01:59:42 once unbound: [12262:0] info: 0.004096 0.008192 1
Oct 27 01:59:42 once unbound: [12262:0] info: 0.016384 0.032768 2
Oct 27 01:59:42 once unbound: [12262:0] info: 0.032768 0.065536 7
Oct 27 01:59:42 once unbound: [12262:0] info: 0.065536 0.131072 151
Oct 27 01:59:42 once unbound: [12262:0] info: 0.131072 0.262144 116
Oct 27 01:59:42 once unbound: [12262:0] info: 0.262144 0.524288 28
Oct 27 01:59:42 once unbound: [12262:0] info: 0.524288 1.000000 11
Oct 27 01:59:42 once unbound: [12262:0] info: 1.000000 2.000000 5
Oct 27 01:59:42 once unbound: [12262:0] info: 2.000000 4.000000 1
Oct 27 01:59:42 once unbound: [12262:0] info: 4.000000 8.000000 2
Oct 27 01:59:42 once unbound: [12262:0] info: 8.000000 16.000000 5
Oct 27 01:59:42 once unbound: [12262:0] info: 16.000000 32.000000 11
Oct 27 01:59:42 once unbound: [12262:0] info: 32.000000 64.000000 11
Oct 27 01:59:42 once unbound: [12262:0] info: 64.000000 128.000000 12
Oct 27 01:59:42 once unbound: [12262:0] info: 128.000000 256.000000 3
Oct 27 01:59:42 once unbound: [12262:0] info: 256.000000 512.000000 4
Oct 27 02:01:24 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:01:24 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:01:24 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:01:24 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:01:25 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:01:26 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:01:35 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:01:36 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:01:56 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:01:57 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:03 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:03 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:03 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:03 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:13 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:13 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:14 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:15 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:16 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:17 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:35 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:35 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:35 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:35 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:35 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:35 once last message repeated 2 times
Oct 27 02:02:35 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:35 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:35 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:35 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:35 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:35 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:35 once last message repeated 2 times
Oct 27 02:02:35 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:36 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:36 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:36 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:36 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:36 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:36 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:36 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:36 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:38 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:38 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:38 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:38 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:39 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:39 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:40 once unbound: [12262:0] error: find_delegation: addrs out of memory
Oct 27 02:02:40 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:44 once last message repeated 3 times
Oct 27 02:02:44 once unbound: [12262:0] error: mesh_state_attachment: out of memory
Oct 27 02:02:44 once last message repeated 275 times
Oct 27 02:02:44 once unbound: [12262:0] error: malloc failure: allocating incoming dns_msg
Oct 27 02:02:45 once last message repeated 18 times
Oct 27 02:02:48 once unbound: [12262:0] fatal error: prealloc: out of memory
--
Greg A. Woods
Planix, Inc.
<woods at planix.com> +1 416 218 0099 http://www.planix.com/
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 186 bytes
Desc: not available
URL: <http://lists.nlnetlabs.nl/pipermail/unbound-users/attachments/20091027/402c5da1/attachment.bin>
More information about the Unbound-users
mailing list