Almost empty and not loaded ns-slapd high cpu load

[jpVm5jYYRE1VIKL]

Issue Description
Almost empty and not loaded 389ds high cpu load.
Restart of container does not solve issue.
Logs does not contain any errors.

strace attached to ns-slapd show following :

clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0

DB Monitor Report: 2022-11-30 14:33:26
--------------------------------------------------------
Database Cache:
 - Cache Hit Ratio:     86%
 - Free Space:          497.21 MB
 - Free Percentage:     100.0%
 - RO Page Drops:       0
 - Pages In:            14
 - Pages Out:           0

Normalized DN Cache:
 - Cache Hit Ratio:     86%
 - Free Space:          19.98 MB
 - Free Percentage:     99.9%
 - DN Count:            127
 - Evictions:           0

Backends:
  - dc=new,dc=com (userRoot):
    - Entry Cache Hit Ratio:        67%
    - Entry Cache Count:            10
    - Entry Cache Free Space:       1.31 GB
    - Entry Cache Free Percentage:  100.0%
    - Entry Cache Average Size:     4.39 KB
    - DN Cache Hit Ratio:           0%
    - DN Cache Count:               10
    - DN Cache Free Space:          192.0 MB
    - DN Cache Free Percentage:     100.0%
    - DN Cache Average Size:        78.0 B

Package Version and Platform:
Docker

Steps to Reproduce
Not clear.

[jpVm5jYYRE1VIKL]

I think that core of issue is : 1000000 is 0.001 of seconds . Due to it nanosleep call executes 1000 times per second and eat host cpu power. In case if nanosleep used to wait for event better to implement it using poll instead or if nanosleep critically needed then to exit from nanosleep early than timer expired need to implement signal handler. Or may be it will be good to have also a crutch solution - adjustable nanosleep delay config setting.

[Firstyear]

@jpVm5jYYRE1VIKL Can you pinpoint which call to clock_nanosleep is causing this? A stack trace or similar? That would really help.

[obaterspok]

It's fixed by this: #5813
That will lower the cpu usage but there are still places where I assume we could sleep more

[mreynolds389]

@obaterspok - you didn't have to close the PR :-) We just wanted you to update the commit. Could file it again? Or are you still working on it?

[obaterspok]

@mreynolds389 - I'm sorry, I took a shortcut with the PR as I just edited the code directly on github and I just couldn't figure out how I would squash it. Therefor I have cloned it now and will resend it shortly

btw, do you want it as usleep(500 * 1000); or as DS_Sleep(PR_MillisecondsToInterval(500));?

[mreynolds389]

@mreynolds389 - I'm sorry, I took a shortcut with the PR as I just edited the code directly on github and I just couldn't figure out how I would squash it. Therefor I have cloned it now and will resend it shortly

btw, do you want it as usleep(500 * 1000); or as DS_Sleep(PR_MillisecondsToInterval(500));?

Hmm, it doesn't really matter. Well we don't use usleep anywhere else in the code, but for consistency I guess use the DS_Sleep() function.

[obaterspok]

I kept usleep as it was quite convenient due to nanosleep output in the strace instead of pselect. Hope it was okay

[mreynolds389]

642760b..a9f687e 389-ds-base-2.3 -> 389-ds-base-2.3
e8114bc..fdce42d 389-ds-base-2.2 -> 389-ds-base-2.2

Thanks for the contribution @obaterspok !

[mreynolds389]

I kept usleep as it was quite convenient due to nanosleep output in the strace instead of pselect. Hope it was okay

Sounds like a perfect reason to keep it, thanks!