[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: 2.3.14 problem?



I have the same problem.

I have noticed something. When i fill empty LDAP from ldif backup, adding 1000
objects is OK, but 1001 and others are added very slow (1-2s for each) and from
this point, slapd 'eat' 99% of my CPU.

This operation on 2.3.11 and 2.3.13 works fine.

Allan E. Johannesen wrote:
> Has anyone seen a looping condition on 2.3.14 (and maybe lesser with 2.3.13) ?
> 
> I don't know how to form this problem into something that can be debugged.
> 
> Anyway, I had trouble with 2.3.14 on RHEL4, BerkelyDB.4.2 (patched)
> 
> Going back to a RedHat Linux 7 system, again with 4.2.52, which I typically use
> to check out new releases, I ran some tests:
> 
> On 2.3.13, I ran this update of a prototype database:
> 
> # ./daily_load -u
> 5393 modified; 30 added; 36382 scanned; 59 deceased; 3:58 elapsed
> 
> Essentially, it reads the whole database, but only updates changed entries.
> 
> It used some small CPU time across the slapd processes:
> 
> # ps auxww|grep ldap
> USER       PID %CPU %MEM   VSZ  RSS TTY      STAT START   TIME COMMAND
> root     25639  0.0  9.9 431208 206056 ?     S    12:38   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25640  0.0  9.9 431208 206056 ?     S    12:38   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25641  0.4  9.9 431208 206056 ?     S    12:38   0:06 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25642  2.7  9.9 431208 206056 ?     S    12:38   0:39 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25644  1.8  9.9 431208 206056 ?     S    12:38   0:26 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25645  1.9  9.9 431208 206056 ?     S    12:38   0:28 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25646  2.0  9.9 431208 206056 ?     S    12:38   0:29 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25647  1.9  9.9 431208 206056 ?     S    12:38   0:28 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25648  1.7  9.9 431208 206056 ?     S    12:38   0:24 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     25649  1.9  9.9 431208 206056 ?     S    12:38   0:28 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> 
> Nothing else was hitting the server in this test environment.
> 
> On 2.3.14, the update from the same starting base seemed to have stalled, so I
> control-C'd it:
> 
> # ./daily_load -u
> SIGINT
> 218 modified; 0 added; 1476 scanned; 3 deceased; 3:32 elapsed
> 
> One of the server processes had run up lots of CPU time:
> 
> # ps auxww|grep ldap
> USER       PID %CPU %MEM   VSZ  RSS TTY      STAT START   TIME COMMAND
> root     11029  0.0  6.8 408704 141300 ?     S    12:19   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11030  0.0  6.8 408704 141300 ?     S    12:19   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11031 87.3  6.8 408704 141300 ?     S    12:19   3:19 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11032  0.5  6.8 408704 141300 ?     S    12:19   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11116  0.4  6.8 408704 141300 ?     S    12:20   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11117  0.5  6.8 408704 141300 ?     S    12:20   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11118  0.9  6.8 408704 141300 ?     S    12:20   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11119  0.3  6.8 408704 141300 ?     S    12:20   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11120  0.7  6.8 408704 141300 ?     S    12:20   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11121  0.3  6.8 408704 141300 ?     S    12:20   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11122  0.9  6.8 408704 141300 ?     S    12:20   0:02 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     11123  0.7  6.8 408704 141300 ?     S    12:20   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> 
> Running it again from the same initial database (slapad'd with the
> 2.3.14 routine) with the same changes:
> 
> # ./daily_load -u
> SIGINT
> 245 modified; 0 added; 1674 scanned; 3 deceased; 4:03 elapsed
> 
> I thought that it stalled at a different point, but now I realize that it's
> ticking along, but at a much slower rate than a healthy 2.3.13 had...
> 
> The CPU of that process does not continue to run up time after the client
> termination.  Starting the update client again does resume the compute behavior
> of that single process.  The other processes appear to gain only small amounts
> of time.  Maybe they're on a path to run up as much time as the 2.3.13 setup,
> but it's going to take a long time for them to get there.
> 
> The 2.3.13 update scanned 36,382 entries in 3:58 elapsed, or 152 per
> second, let alone that it did 5,393 updates, which should be the more
> time-consuming activity.  2.3.14 runs at 1 or 2 per second after it bogs down.
> 
> Running the update again, and letting it continue with some debugging turned on
> in the client, I see that updates are occuring, and they're not returning
> errors, it's just running slowly and that single server process is really
> running up compute time.
> 
> Again, there are no other clients accessing the data, thus no contention.
> 
> I had seen some looping incidents on the 2.3.13 version, but only on the slave,
> and had hoped for a fix in 2.3.14, but 2.3.14 has this problem worse than .13
> had.  The situation was rare in .13, but it did happen.
> 
> Here's the condition much farther on.  The other server processes had gained a
> little time, but it's really that single one that crunches time:
> 
> # ps auxww|grep ldap
> USER       PID %CPU %MEM   VSZ  RSS TTY      STAT START   TIME COMMAND
> root     10122  0.0  6.9 408228 142788 ?     S    14:21   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10123  0.0  6.9 408228 142788 ?     S    14:21   0:00 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10124 96.5  6.9 408228 142788 ?     R    14:21  11:11 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10125  0.2  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10131  0.2  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10132  0.3  6.9 408228 142788 ?     S    14:21   0:02 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10134  0.1  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10135  0.1  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10136  0.1  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10137  0.1  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10138  0.2  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> root     10139  0.1  6.9 408228 142788 ?     S    14:21   0:01 servers/slapd/slapd -f /usr/local/etc/openldap/slapd.utility5.alum.conf
> 
> I tried using -d-1 after restarting the server after the "slowness" problem had
> started to be observed, but nothing unusual appeared in the debugging (to my
> untrained eye, anyway).
> 
> Does anyone have a clue about how to set up a debugging situation?  Has anyone
> else seen this?
> 


-- 
========================
MichaÅ Kasperczyk
Programista
Departament Integracji i WdroÅeÅ

tel: +48 32 33 25 680
kom: +48 606 218 360
fax: +48 32 33 25 505
email: m.kasperczyk@wasko.pl
-----------------------------------
WASKO S.A.
ul. Berbeckiego 6
44-100 Gliwice
-----------------------------------
OddziaÅ Gliwice
ul. Berbeckiego 6
44-100 Gliwice
-----------------------------------
Dokument ten zawiera informacje poufne, ktÃre mogÄ byÄ rÃwnieÅ objÄte tajemnicÄ
sÅuÅbowÄ. Jest on przeznaczony do wyÅÄcznego uÅytku adresata. JeÅli nie sÄ
PaÅstwo jego adresatem, to wszelkie rozpowszechnianie, dystrybucja, reprodukcja,
kopiowanie, publikacja lub wykorzystanie tego dokumentu lub informacji jest
zabronione. JeÅli otrzymali PaÅstwo tÄ wiadomoÅÄ przez pomyÅkÄ, prosimy o
bezzwÅoczne skontaktowanie siÄ z nami oraz usuniÄcie wiadomoÅci z PaÅstwa komputera.

This e-mail may contain confidential and/or privileged information. If you are
not the intended recipient  (or have received this e-mail by mistake) please
notify the sender immediately and destroy this e-mail. Any unauthorized copying,
disclosure or distribution  of the material in this e-mail is strictly forbidden.




begin:vcard
fn;quoted-printable:Micha=C5=82 Kasperczyk
n;quoted-printable:Kasperczyk;Micha=C5=82
email;internet:m.kasperczyk@wasko.pl
x-mozilla-html:FALSE
version:2.1
end:vcard

Attachment: smime.p7s
Description: S/MIME Cryptographic Signature