[Samba] High named cpu

Mon Dec 18 17:31:42 UTC 2017

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?

-- 
Kv,
Kristján Valur Jónsson, RVX