[Samba] High named cpu

Mon Dec 18 17:46:49 UTC 2017

On Mon, 18 Dec 2017 17:31:42 +0000
Kristján Valur Jónsson via samba <samba at lists.samba.org> wrote:

> Hi there.
> I'm running an AD DC in a KVM VM, a centos7 server.
> named is showing a very hight cpu usage, close to 100%.  I just
> increased the number of CPUs to 2 to cope.
> This is a small company, with perhaps 20 workstations and another 20
> linux servers.  There shouldn't be that much happening.
> 
> top - 17:27:48 up  2:29,  1 user,  load average: 1.08, 1.13, 1.09
> Tasks: 139 total,   1 running, 138 sleeping,   0 stopped,   0 zombie
> %Cpu(s): 49.7 us,  0.8 sy,  0.0 ni, 49.1 id,  0.0 wa,  0.0 hi,  0.3
> si, 0.0 st
> KiB Mem :   735668 total,   203860 free,   299444 used,   232364
> buff/cache KiB Swap:  4063228 total,  4033608 free,    29620 used.
> 177296 avail Mem
> 
>   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+
> COMMAND 2011 named     20   0  646880  64712  11924 S 100.3  8.8
> 128:53.76 named 9 root      20   0       0      0      0 S   0.3
> 0.0   0:37.72 rcu_sched
>  1188 root      20   0  567080  24216   5688 S   0.3  3.3   0:10.12
> samba
> 
> 
> Doing a stack trace of the running process shows me a lot of samba_dlz
> activity:
> 
> [root at dc01 ~]# pstack 2011
> Thread 5 (Thread 0x7fac16291700 (LWP 2012)):
> #0  0x00007fac0f1ea48f in ldb_dn_explode () from
> /usr/local/samba/lib/private/libldb.so.1
> #1  0x00007fac0f1eb615 in ldb_dn_casefold_internal () from
> /usr/local/samba/lib/private/libldb.so.1
> #2  0x00007fac0f1eb8c8 in ldb_dn_get_casefold () from
> /usr/local/samba/lib/private/libldb.so.1
> #3  0x00007fabfa856c84 in ltdb_key ()
> from /usr/local/samba/lib/ldb/tdb.so #4  0x00007fabfa85a0e0 in
> ltdb_search_dn1 () from /usr/local/samba/lib/ldb/tdb.so
> #5  0x00007fabfa85c950 in ltdb_index_filter () from
> /usr/local/samba/lib/ldb/tdb.so
> #6  0x00007fabfa85cee8 in ltdb_search_indexed () from
> /usr/local/samba/lib/ldb/tdb.so
> #7  0x00007fabfa85abf5 in ltdb_search () from
> /usr/local/samba/lib/ldb/tdb.so
> #8  0x00007fabfa859384 in ltdb_callback () from
> /usr/local/samba/lib/ldb/tdb.so
> #9  0x00007fac0d187a52 in tevent_common_loop_timer_delay () from
> /usr/local/samba/lib/private/libtevent.so.0
> #10 0x00007fac0d189d5c in epoll_event_loop_once () from
> /usr/local/samba/lib/private/libtevent.so.0
> #11 0x00007fac0d186ae3 in std_event_loop_once () from
> /usr/local/samba/lib/private/libtevent.so.0
> #12 0x00007fac0d18042a in _tevent_loop_once () from
> /usr/local/samba/lib/private/libtevent.so.0
> #13 0x00007fac0f1fefa2 in ldb_wait () from
> /usr/local/samba/lib/private/libldb.so.1
> #14 0x00007fac0f879d18 in dns_wildcard_lookup () from
> /usr/local/samba/lib/private/libdnsserver-common-samba4.so
> #15 0x00007fac0f879ecc in dns_common_wildcard_lookup () from
> /usr/local/samba/lib/private/libdnsserver-common-samba4.so
> #16 0x00007fac0fcb4995 in dlz_lookup_types () from
> /usr/local/samba/lib/bind9/dlz_bind9_9.so
> #17 0x00007fac0fcb4ada in dlz_lookup () from
> /usr/local/samba/lib/bind9/dlz_bind9_9.so
> #18 0x000055f8ccd74706 in dlopen_dlz_lookup ()
> #19 0x00007fac19fa5a39 in findnodeext () from /lib64/libdns.so.100
> #20 0x00007fac19fa6495 in findext () from /lib64/libdns.so.100
> #21 0x000055f8ccd3f0b9 in query_addadditional ()
> #22 0x000055f8ccd418e6 in query_addadditional2 ()
> #23 0x00007fac19f76abe in dns_rdata_additionaldata () from
> /lib64/libdns.so.100
> #24 0x00007fac19f83e01 in dns_rdataset_additionaldata () from
> /lib64/libdns.so.100
> #25 0x000055f8ccd3c83e in query_addrrset ()
> #26 0x000055f8ccd46512 in query_find ()
> #27 0x000055f8ccd4e15d in ns_query_start ()
> #28 0x000055f8ccd2d831 in client_request ()
> #29 0x00007fac188550c6 in run () from /lib64/libisc.so.95
> #30 0x00007fac18405e25 in start_thread () from /lib64/libpthread.so.0
> #31 0x00007fac1747d34d in clone () from /lib64/libc.so.6
> Thread 4 (Thread 0x7fac15a90700 (LWP 2013)):
> #0  0x00007fac1840c42d in __lll_lock_wait ()
> from /lib64/libpthread.so.0 #1  0x00007fac18407dcb in _L_lock_812 ()
> from /lib64/libpthread.so.0 #2  0x00007fac18407c98 in
> pthread_mutex_lock () from /lib64/libpthread.so.0 #3
> 0x000055f8ccd74819 in dlopen_dlz_findzonedb () #4  0x00007fac19fa5471
> in dns_sdlzfindzone () from /lib64/libdns.so.100 #5
> 0x00007fac19ee91c6 in dns_dlzfindzone () from /lib64/libdns.so.100
> #6  0x000055f8ccd44591 in query_find () #7  0x000055f8ccd4e15d in
> ns_query_start () #8  0x000055f8ccd2d831 in client_request ()
> #9  0x00007fac188550c6 in run () from /lib64/libisc.so.95
> #10 0x00007fac18405e25 in start_thread () from /lib64/libpthread.so.0
> #11 0x00007fac1747d34d in clone () from /lib64/libc.so.6
> Thread 3 (Thread 0x7fac1528f700 (LWP 2014)):
> #0  0x00007fac18409cf2 in pthread_cond_timedwait@@GLIBC_2.3.2 () from
> /lib64/libpthread.so.0
> #1  0x00007fac1886e868 in isc_condition_waituntil () from
> /lib64/libisc.so.95
> #2  0x00007fac18859913 in run () from /lib64/libisc.so.95
> #3  0x00007fac18405e25 in start_thread () from /lib64/libpthread.so.0
> #4  0x00007fac1747d34d in clone () from /lib64/libc.so.6
> Thread 2 (Thread 0x7fac14a8e700 (LWP 2015)):
> #0  0x00007fac1747d923 in epoll_wait () from /lib64/libc.so.6
> #1  0x00007fac18866336 in watcher () from /lib64/libisc.so.95
> #2  0x00007fac18405e25 in start_thread () from /lib64/libpthread.so.0
> #3  0x00007fac1747d34d in clone () from /lib64/libc.so.6
> Thread 1 (Thread 0x7fac1a683840 (LWP 2011)):
> #0  0x00007fac173ba572 in sigsuspend () from /lib64/libc.so.6
> #1  0x00007fac1885c17c in isc__app_ctxrun () from /lib64/libisc.so.95
> #2  0x000055f8ccd28525 in main ()
> 
> 
> Usually one thread is deep down in some dlz_lookup, while the other is
> waiting for a mutex.
> Turning up debugging for named.conf shows no errors, just a bunch of
> lookups for my forward and reverse zones.
> 
> Is this kind of load expected?
> 
> 
> 

Unfortunately, it seems it is at the moment, though it is actively
being worked on. 

Rowland