[Freeipa-users] I/O Problems after update to IPA Version RHEL6.4

Thu Jun 27 19:33:47 UTC 2013

With heavy load I mean that the ldap process is consuming MUCH more CPU usage then before. 
As you can see from the top screenshot is that I/O Wait is 54.4% and CPU around 50% this is way too much. And this is not good.
Before it was always around 0-1%.

I see that the db log files for the slapd are changed and updated over and over again. This might indicate loads of changes in the db. But I cannot explain those changes, as currently nothing should be going on.

What I also found in the logs is this message.
Don't know what that means:
[27/Jun/2013:19:10:12 +0200] - Retry count exceeded in modify
[27/Jun/2013:20:18:43 +0200] - Retry count exceeded in modify
[27/Jun/2013:21:20:44 +0200] - Retry count exceeded in modify

Hope this makes it a little more clear.

Thanks Marc.
----- Original Message -----
From: "Rich Megginson" <rmeggins at redhat.com>
To: "Marc Grimme" <grimme at atix.de>
Cc: freeipa-users at redhat.com
Sent: Thursday, June 27, 2013 9:24:17 PM
Subject: Re: [Freeipa-users] I/O Problems after update to IPA Version RHEL6.4

On 06/27/2013 01:11 PM, Marc Grimme wrote:
> Hi together,
> I updated my ipa servers last week.
> Since then the primary master is running under heavy load.

What exactly do you mean by "heavy load"?

> It look like that the ldap server reponsible for my domain is causing high I/O load.

Where do you see high I/O load?

> It's writing its logs over and over again.

What do you mean by that?

> Also the CPU is loaded:
> top - 21:09:53 up 6 days,  4:18,  2 users,  load average: 1.73, 1.71, 1.74
> Tasks: 107 total,   1 running, 106 sleeping,   0 stopped,   0 zombie
> Cpu0  : 37.5%us,  1.9%sy,  0.0%ni,  0.0%id, 54.4%wa,  0.0%hi,  0.0%si,  6.2%st
> Mem:   1922724k total,  1547748k used,   374976k free,   133928k buffers
> Swap:  2064376k total,     1812k used,  2062564k free,   233944k cached
>
>    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> 32134 dirsrv    20   0 1626m 652m  16m S 35.8 34.8  66:33.38 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-CL-ATIX -i /var/run/dirsrv/slapd-CL-ATIX.pid -w /var/run/d
>    912 root      20   0  314m  47m 7220 S  5.3  2.6   0:02.11 /usr/bin/python -E /usr/sbin/ipa-replica-manage list
>   2012 root      20   0  192m 5280 1536 S  0.3  0.3   3:43.13 /usr/sbin/snmpd -LS0-6d -Lf /dev/null -p /var/run/snmpd.pid
>      1 root      20   0 21304 1352 1092 S  0.0  0.1   0:06.61 /sbin/init
>      2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 [kthreadd]
> ...

What would you expect to see instead of the above numbers?  What do you 
mean by "CPU is loaded"?  CPU% 35.8 is not necessarily bad or good.

>
> Look at two following ls on the db directory.
> -----------------------X8--------------------------------
> [root at axinfra01-1 dirsrv]# ls -l /var/lib/dirsrv/slapd-CL-ATIX/db
> insgesamt 155484
> -rw------- 1 dirsrv dirsrv    24576 27. Jun 17:37 __db.001
> -rw------- 1 dirsrv dirsrv  1728512 27. Jun 21:07 __db.002
> -rw------- 1 dirsrv dirsrv 10002432 27. Jun 21:07 __db.003
> -rw------- 1 dirsrv dirsrv  1081344 27. Jun 21:07 __db.004
> -rw------- 1 dirsrv dirsrv  8126464 27. Jun 21:08 __db.005
> -rw------- 1 dirsrv dirsrv    90112 27. Jun 21:07 __db.006
> -rw------- 1 dirsrv dirsrv       49 27. Jun 17:37 DBVERSION
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289597
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289598
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289599
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289600
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289601
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289602
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289603
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289604
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289605
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289606
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289607
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289608
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289609
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289610
> drwx------ 2 dirsrv dirsrv     4096 21. Jun 16:48 userRoot
> [root at axinfra01-1 dirsrv]# ls -l /var/lib/dirsrv/slapd-CL-ATIX/db
> insgesamt 191500
> -rw------- 1 dirsrv dirsrv    24576 27. Jun 17:37 __db.001
> -rw------- 1 dirsrv dirsrv  1728512 27. Jun 21:07 __db.002
> -rw------- 1 dirsrv dirsrv 10002432 27. Jun 21:07 __db.003
> -rw------- 1 dirsrv dirsrv  1081344 27. Jun 21:07 __db.004
> -rw------- 1 dirsrv dirsrv  8126464 27. Jun 21:08 __db.005
> -rw------- 1 dirsrv dirsrv    90112 27. Jun 21:07 __db.006
> -rw------- 1 dirsrv dirsrv       49 27. Jun 17:37 DBVERSION
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289597
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289598
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289599
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289600
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289601
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289602
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289603
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289604
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289605
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289606
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:07 log.0000289607
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289608
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289609
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289610
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289611
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289612
> -rw------- 1 dirsrv dirsrv 10485760 27. Jun 21:08 log.0000289613
> ----------------------------X8------------------------------------

There are a lot of transaction logs, but not too many, for write 
intensive applications.

>
> All the apps are pretty slow with authentication.
logconv.pl - man logconv.pl
>
> The server is exclusivly running ipa.
>
> Any ideas how I can proceed?
>
> Thanks for you help.
>
> Marc.
>