[Freeipa-users] ns-slapd using all CPU ressources

[Domingues Luis Filipe]

Hi,

Reading the backtrace I have 30 threads with the same stack:

Thread 6 (Thread 0x7f572efed700 (LWP 1335)):
#0  0x00007f576f80a877 in sched_yield () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007f577014df28 in PR_Sleep () from /lib64/libnspr4.so
No symbol table info available.
#2  0x000055c939e9e7c7 in connection_threadmain ()
No symbol table info available.
#3  0x00007f577014d5cb in _pt_root () from /lib64/libnspr4.so
No symbol table info available.
#4  0x00007f576faec60a in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5  0x00007f576f826a4d in clone () from /lib64/libc.so.6
No symbol table info available.

While the other instance which is running fine, almost all threads are waiting on a cond_wait, with thise stack:
Thread 48 (Thread 0x7fced53a9700 (LWP 1871)):
#0  0x00007fcee9269b10 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
No symbol table info available.
#1  0x00007fcee98bfcf0 in PR_WaitCondVar () from /lib64/libnspr4.so
No symbol table info available.
#2  0x00007fceeb7172c8 in slapi_wait_condvar () from /usr/lib64/dirsrv/libslapd.so.0
No symbol table info available.
#3  0x00007fcee127a67e in cos_cache_wait_on_change () from /usr/lib64/dirsrv/plugins/libcos-plugin.so
No symbol table info available.
#4  0x00007fcee98c55cb in _pt_root () from /lib64/libnspr4.so
No symbol table info available.
#5  0x00007fcee926460a in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#6  0x00007fcee8f9ea4d in clone () from /lib64/libc.so.6
No symbol table info available.

Luis.
________________________________________
From: Rob Crittenden [rcritten at redhat.com]
Sent: Friday, January 15, 2016 3:51 PM
To: Domingues Luis Filipe; freeipa-users at redhat.com
Cc: Aviolat Romain
Subject: Re: [Freeipa-users] ns-slapd using all CPU ressources

Domingues Luis Filipe wrote:
> Hi all,
>
> On our infra, we have two machines running Fedora with FreeIPA installed.
>
> we have an issue with ns-slapd using 100% of CPU after a while. If we
> restart the service, it starts to use all CPU resources after one day.
>
> Outpute of the command strace -c -p <ns-slapd PID> running for 4 minutes is:
>
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  99.80  229.603633       11247     20415           poll
>   0.15    0.340032          10     32983         4 futex
>   0.05    0.114068      114068         1           restart_syscall
>   0.00    0.003464           0     20420     20416 getpeername
>   0.00    0.002752           0     20416           clock_gettime
>   0.00    0.001920           0      9840           read
>   0.00    0.000205           5        45           close
>   0.00    0.000036           2        22           access
>   0.00    0.000017           1        22           open
>   0.00    0.000016           1        24           accept
>   0.00    0.000012           0        45           setsockopt
>   0.00    0.000007           0        22           fstat
>   0.00    0.000000           0        22           stat
>   0.00    0.000000           0         1           sendto
>   0.00    0.000000           0        24           getsockname
>   0.00    0.000000           0         4           getsockopt
>   0.00    0.000000           0        70           fcntl
>   0.00    0.000000           0        22           gettimeofday
> ------ ----------- ----------- --------- --------- ----------------
> 100.00  230.066162                104398     20420 total
>
>
>
> Plus we looked at the syscalls using FTrace:
>
> ns-slapd-7963  [000] .... 4063846.395630: sys_sched_yield()
> ns-slapd-7956  [000] .... 4063846.395631: sys_sched_yield -> 0x0
> ns-slapd-7956  [000] .... 4063846.395632: sys_sched_yield()
> ns-slapd-7973  [000] .... 4063846.395633: sys_sched_yield -> 0x0
> ns-slapd-7973  [000] .... 4063846.395634: sys_sched_yield()
> ns-slapd-7965  [000] .... 4063846.395635: sys_sched_yield -> 0x0
> ns-slapd-7965  [000] .... 4063846.395637: sys_sched_yield()
> ns-slapd-7963  [000] .... 4063846.395637: sys_sched_yield -> 0x0
> ns-slapd-7963  [000] .... 4063846.395639: sys_sched_yield()
> ns-slapd-7956  [000] .... 4063846.395640: sys_sched_yield -> 0x0
> ns-slapd-7956  [000] .... 4063846.395641: sys_sched_yield()
> ns-slapd-7973  [000] .... 4063846.395642: sys_sched_yield -> 0x0
> ns-slapd-7973  [000] .... 4063846.395643: sys_sched_yield()
> ns-slapd-7965  [000] .... 4063846.395644: sys_sched_yield -> 0x0
>
> The sys_sched_yield function is called almost every 2 microseconds. It seems too much.

Your best bet is to get a pstack or full backtrace to see what 389-ds is
doing. See
http://directory.fedoraproject.org/docs/389ds/FAQ/faq.html#debugging-hangs

rob