Thank you for the data, I think I understand now what is going on.
In the error logs we see only message like (from my test env):
[16/Jul/2015:10:12:40 +0200] NSMMReplicationPlugin - agmt="cn=100-300"
(localhost:9759): replay_update: modifys operation
(dn="dc=example,dc=com" csn=55a82a29000100640000) not sent - empty
[16/Jul/2015:10:12:40 +0200] NSMMReplicationPlugin - agmt="cn=100-300"
(localhost:9759): replay_update: Consumer successfully sent operation
with csn 55a82a29000100640000
[16/Jul/2015:10:12:40 +0200] NSMMReplicationPlugin - agmt="cn=100-300"
(localhost:9759): Skipping update operation with no message_id (uniqueid
7507cb26-e8ac11e2-b2898005-8430f734, CSN 55a82a29000100640000):
This happens if fractional replication is configured as IPA does and the
changes affect only attributes which will NOT be replicated. So teh
local RUV will be updated, but since no change is really sent, the
consumer RUV is not updated and replciation will always set off from an
very old starting csn. It is a rare scenario where a server receives
only mods which are not replicated.
I have opened a ticket for this: https://fedorahosted.org/389/ticket/48225
As a workaround can you try to apply a mod on m14-26 which will not be
stripped, either create a dummy user or add a description attribute to
an existing object. Repliciation will once again iterate thru all the
changes (which can take a while), but then should replay this latest
change and define a new offset
Regards,
Ludwig
On 07/15/2015 07:05 PM, Andrew E. Bruno wrote:
On Wed, Jul 15, 2015 at 04:58:23PM +0200, Ludwig Krispenz wrote:
On 07/15/2015 04:10 PM, Andrew E. Bruno wrote:
On Wed, Jul 15, 2015 at 03:22:51PM +0200, Ludwig Krispenz wrote:
On 07/14/2015 08:59 PM, Andrew E. Bruno wrote:
On Tue, Jul 14, 2015 at 04:52:10PM +0200, Ludwig Krispenz wrote:
hm, the stack traces show csn_str, which correspond to Jul,8th, Jul,4th, and
Jul,7th - so it looks like it is iterating the changelog over and over
again.
Th consumer side Is "cn=meTosrv-m14-24.ccr.buffalo.edu" - is this the master
?
can you provide the result of the following search from
m14-24.ccr.buffalo.edu adn the server with the high cpu:
ldapsearch -o ldif-wrap=no -x -D ... -w -b "cn=config"
"objectclass=nsds5replica" nsds50ruv
master is srv-m14-24.. here's the results of the ldapsearch:
[srv-m14-24 ~]$ ldapsearch -o ldif-wrap=no -x -D "cn=directory manager" -W -b
"cn=config" "objectclass=nsds5replica" nsds50ruv
# replica, dc\3Dccr\2Cdc\3Dbuffalo\2Cdc\3Dedu, mapping tree, config
dn: cn=replica,cn=dc\3Dccr\2Cdc\3Dbuffalo\2Cdc\3Dedu,cn=mapping tree,cn=config
nsds50ruv: {replicageneration} 5527f711000000040000
nsds50ruv: {replica 4 ldap://srv-m14-24.ccr.buffalo.edu:389}
5527f771000000040000 55a55aed001000040000
nsds50ruv: {replica 5 ldap://srv-m14-26.ccr.buffalo.edu:389}
5537c773000000050000 5591a3d2000700050000
nsds50ruv: {replica 6 ldap://srv-m14-25-02.ccr.buffalo.edu:389}
55943dda000000060000 55945378000200060000
so this is really strange, the master m14-24 has the latest change from
replica 5(m14-26) as: 5591a3d2000700050000
which corresponds to Mon, 29 Jun 2015 20:00:18 GMT
so no update from 14-24 since that did arrive, or could not update the ruv.
So m14-26 tries to replicate all the changes back from that time, but looks
like iit has no success.
is there anything in the logs of m14-24 ? can you see successful mods with
csn=xxxxxxx00050000 ?
Here's what I could find from the logs on srv-m14-24:
[srv-m14-24 ~]# grep -r 00050000 /var/log/dirsrv/slapd-[domain]/*
access.20150714-014346:[14/Jul/2015:03:10:05 -0400] conn=748529 op=14732 RESULT
err=0 tag=103 nentries=0 etime=1 csn=55a4b5f0005000040000
ok, so no update originating at replica 5 has been replicated (probably
since June,29) did you experience data inconsistency between the servers ?
And here's the last few lines the error log on srv-m14-24:
one set of messages refers to the o=ipaca backend and seem to be transient,
replication continues later.
the other set of msg "No original tombstone .." is annoying (and it is fixed
in ticket https://fedorahosted.org/389/ticket/47912)
the next thing we can do to try to understand what is going on is to enable
replication logging on m14-26, it will then not only consume all cpu, but
write tons of messages to the error log.
But it can be turned on and off:
ldapmodify ...
dn: cn=config
replace: nsslapd-errorlog-level
nsslapd-errorlog-level: 8192
and let it run for a while, then set it back to: 0
I enabled replication logging and it's running now. I noticed the
default value for nsslapd-errorlog-level was set to 16384 (not 0).
OK to send you the logs off list? Looks like they contain quite a bit of
sensitive data.
Thanks again for all the help looking into this.
Best,
--Andrew
[12/Jul/2015:10:11:14 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2456070,cn=changelog!!
[12/Jul/2015:10:11:48 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2498441,cn=changelog!!
[13/Jul/2015:07:41:49 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a3a406000000600000): Operations error (1).
Will retry later.
[13/Jul/2015:11:56:50 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a3dfca000000600000): Operations error (1).
Will retry later.
[13/Jul/2015:14:26:50 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a402f2000000600000): Operations error (1).
Will retry later.
[13/Jul/2015:15:26:49 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a41102000000600000): Operations error (1).
Will retry later.
[13/Jul/2015:18:26:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a43b32000000600000): Operations error (1).
Will retry later.
[13/Jul/2015:18:56:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a4423a000000600000): Operations error (1).
Will retry later.
[13/Jul/2015:20:41:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a45ad6000000600000): Operations error (1).
Will retry later.
[13/Jul/2015:22:41:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a476f6000000600000): Operations error (1).
Will retry later.
[14/Jul/2015:06:56:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a4eafa000000600000): Operations error (1).
Will retry later.
[14/Jul/2015:09:56:52 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-srv-m14-26.ccr.buffalo.edu-pki-tomcat"
(srv-m14-26:389): Consumer failed to replay change (uniqueid
cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a5152a000000600000): Operations error (1).
Will retry later.
[14/Jul/2015:10:11:21 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2552223,cn=changelog!!
[14/Jul/2015:10:11:21 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2552224,cn=changelog!!
[14/Jul/2015:10:11:25 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2557315,cn=changelog!!
[14/Jul/2015:10:11:25 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2557318,cn=changelog!!
[14/Jul/2015:10:11:28 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2561020,cn=changelog!!
[14/Jul/2015:10:11:28 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2561043,cn=changelog!!
[14/Jul/2015:10:11:48 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2586022,cn=changelog!!
[14/Jul/2015:10:11:59 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2598989,cn=changelog!!
[14/Jul/2015:10:11:59 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2598990,cn=changelog!!
[14/Jul/2015:10:12:01 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2600966,cn=changelog!!
[14/Jul/2015:10:12:03 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2604037,cn=changelog!!
[14/Jul/2015:10:12:04 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2604054,cn=changelog!!
[14/Jul/2015:10:12:24 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2629803,cn=changelog!!
[14/Jul/2015:10:12:24 -0400] ldbm_back_delete - conn=0 op=0 [retry: 1] No
original_tombstone for changenumber=2629804,cn=changelog!!
# replica, o\3Dipaca, mapping tree, config
dn: cn=replica,cn=o\3Dipaca,cn=mapping tree,cn=config
nsds50ruv: {replicageneration} 5527f74b000000600000
nsds50ruv: {replica 96 ldap://srv-m14-24.ccr.buffalo.edu:389}
5527f754000000600000 55a557f6000000600000
nsds50ruv: {replica 86 ldap://srv-m14-25-02.ccr.buffalo.edu:389}
55943e6e000000560000 55943e6f000100560000
nsds50ruv: {replica 91 ldap://srv-m14-26.ccr.buffalo.edu:389}
5537c7ba0000005b0000 5582c7e40004005b0000
server with high cpu load is srv-m14-26. here's the results of the ldapsearch
>from this server:
[srv-m14-26 ~]$ ldapsearch -o ldif-wrap=no -x -D "cn=directory manager" -W -b
"cn=config" "objectclass=nsds5replica" nsds50ruv
# replica, dc\3Dccr\2Cdc\3Dbuffalo\2Cdc\3Dedu, mapping tree, config
dn: cn=replica,cn=dc\3Dccr\2Cdc\3Dbuffalo\2Cdc\3Dedu,cn=mapping tree,cn=config
nsds50ruv: {replicageneration} 5527f711000000040000
nsds50ruv: {replica 5 ldap://srv-m14-26.ccr.buffalo.edu:389}
5537c773000000050000 55a55b47000300050000
nsds50ruv: {replica 4 ldap://srv-m14-24.ccr.buffalo.edu:389}
5527f771000000040000 55a53eb0000a00040000
nsds50ruv: {replica 6 ldap://srv-m14-25-02.ccr.buffalo.edu:389}
55943dda000000060000 55945378000200060000
# replica, o\3Dipaca, mapping tree, config
dn: cn=replica,cn=o\3Dipaca,cn=mapping tree,cn=config
nsds50ruv: {replicageneration} 5527f74b000000600000
nsds50ruv: {replica 91 ldap://srv-m14-26.ccr.buffalo.edu:389}
5537c7ba0000005b0000 5582c7e40004005b0000
nsds50ruv: {replica 96 ldap://srv-m14-24.ccr.buffalo.edu:389}
5527f754000000600000 55a557f6000000600000
nsds50ruv: {replica 86 ldap://srv-m14-25-02.ccr.buffalo.edu:389}
55943e6e000000560000 55943e6f000100560000
srv-m14-25-02 is our 3rd replicate which we recently added back in after it
failed (was added back in 7/1).
Let me know if you need anything else. Thanks for the help.
--Andrew
On 07/14/2015 02:35 PM, Andrew E. Bruno wrote:
On Tue, Jul 14, 2015 at 01:41:57PM +0200, Ludwig Krispenz wrote:
On 07/13/2015 06:36 PM, Andrew E. Bruno wrote:
On Mon, Jul 13, 2015 at 05:29:13PM +0200, Ludwig Krispenz wrote:
On 07/13/2015 05:05 PM, Andrew E. Bruno wrote:
On Mon, Jul 13, 2015 at 04:58:46PM +0200, Ludwig Krispenz wrote:
can you get a pstack of the slapd process along with a top -H to find th
ethread with high cpu usage
Attached is the full stacktrace of the running ns-slapd proccess. top -H
shows this thread (2879) with high cpu usage:
2879 dirsrv 20 0 3819252 1.962g 11680 R 99.9 3.1 8822:10 ns-slapd
this thread is a replication thread sending updates, what is strange is that
the current csn_str is quite old (july, 7th), I can't tell which agreeement
this thread is handling, but looks like it is heavily reading the changeglog
and sending updates. anything changed recently in replication setup ?
Yes, we had one replica fail on (6/19) which we removed (not this one
showing high CPU load). Had to perform some manual cleanup of the ipa-ca
RUVs. Then we added the replica back in on 7/1. Since then, replication
appears to have been running normally between the 3 replicas. We've been
monitoring utilization since 7/1 and only recently seen this spike (past
24 hours or so).
is it still in this state ? or was it a spike.
Yes same state.
if it still is high cpu consuming, could you
- get a few pstack like the one before with some time in between, I would
like to see if it is progressing with the csns or looping on the same one
Attached are a few stacktraces. The thread pegging the cpu is:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2879 dirsrv 20 0 3819252 1.978g 11684 R 99.9 3.2 10148:26 ns-slapd
- check the consumer side. is there anything in the error log ? does the
access log show replication activity from this server
Here's some errors showing up on the first master server rep1 (rep2 is the
server with pegged cpu):
[13/Jul/2015:20:41:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-rep2-pki-tomcat" (rep2:389): Consumer failed to
replay change (uniqueid cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a45ad6000000600000):
Operations error (1). Will retry later.
[13/Jul/2015:22:41:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-rep2-pki-tomcat" (rep2:389): Consumer failed to
replay change (uniqueid cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a476f6000000600000):
Operations error (1). Will retry later.
[14/Jul/2015:06:56:51 -0400] NSMMReplicationPlugin -
agmt="cn=masterAgreement1-rep2-tomcat" (rep2:389): Consumer failed to replay
change (uniqueid cb7acfc1-df9211e4-a351aa45-2e06257b, CSN 55a4eafa000000600000):
Operations error (1). Will retry later.
Here's some snips from the access log of the rep2:
[14/Jul/2015:08:22:31 -0400] conn=777787 op=9794 EXT oid="2.16.840.1.113730.3.5.5"
name="Netscape Replication End Session"
[14/Jul/2015:08:22:31 -0400] conn=777787 op=9794 RESULT err=0 tag=120
nentries=0 etime=0
[14/Jul/2015:08:22:31 -0400] conn=777787 op=9795 EXT oid="2.16.840.1.113730.3.5.12"
name="replication-multimaster-extop"
[14/Jul/2015:08:22:31 -0400] conn=777787 op=9795 RESULT err=0 tag=120
nentries=0 etime=0
[14/Jul/2015:08:22:33 -0400] conn=777787 op=9796 EXT oid="2.16.840.1.113730.3.5.5"
name="Netscape Replication End Session"
..
[14/Jul/2015:08:23:38 -0400] conn=782341 op=129 RESULT err=0 tag=103 nentries=0
etime=0 csn=55a4ff6c000000050000
..
[14/Jul/2015:08:24:02 -0400] conn=781901 op=1745 RESULT err=0 tag=101
nentries=1 etime=0
[14/Jul/2015:08:24:03 -0400] conn=777787 op=9810 EXT oid="2.16.840.1.113730.3.5.5"
name="Netscape Replication End Session"
[14/Jul/2015:08:24:03 -0400] conn=777787 op=9810 RESULT err=0 tag=120
nentries=0 etime=0
[14/Jul/2015:08:24:03 -0400] conn=777787 op=9811 EXT oid="2.16.840.1.113730.3.5.12"
name="replication-multimaster-extop"
[14/Jul/2015:08:24:03 -0400] conn=777787 op=9811 RESULT err=0 tag=120
nentries=0 etime=0
[14/Jul/2015:08:24:05 -0400] conn=777787 op=9812 EXT oid="2.16.840.1.113730.3.5.5"
name="Netscape Replication End Session"
[14/Jul/2015:08:24:05 -0400] conn=777787 op=9812 RESULT err=0 tag=120
nentries=0 etime=0
[14/Jul/2015:08:24:08 -0400] conn=777787 op=9813 EXT oid="2.16.840.1.113730.3.5.12"
name="replication-multimaster-extop"
[14/Jul/2015:08:24:08 -0400] conn=777787 op=9813 RESULT err=0 tag=120
nentries=0 etime=0
[14/Jul/2015:08:24:10 -0400] conn=777787 op=9814 EXT oid="2.16.840.1.113730.3.5.5"
name="Netscape Replication End Session"
[14/Jul/2015:08:24:10 -0400] conn=777787 op=9814 RESULT err=0 tag=120
nentries=0 etime=0
[14/Jul/2015:08:24:10 -0400] conn=777787 op=9815 EXT oid="2.16.840.1.113730.3.5.12"
name="replication-multimaster-extop"
[14/Jul/2015:08:24:10 -0400] conn=777787 op=9815 RESULT err=0 tag=120
nentries=0 etime=0
and here's some from the error log:
[13/Jul/2015:22:41:49 -0400] DSRetroclPlugin - replog: an error occured while
adding change number 2294859, dn = changenumber=2294859,cn=changelog:
Operations error.
[13/Jul/2015:22:41:49 -0400] retrocl-plugin - retrocl_postob: operation failure
[1]
[13/Jul/2015:23:56:50 -0400] - dn2entry_ext: Failed to get id for
changenumber=2296384,cn=changelog from entryrdn index (-30993)
[13/Jul/2015:23:56:50 -0400] - Operation error fetching
changenumber=2296384,cn=changelog (null), error -30993.
[13/Jul/2015:23:56:50 -0400] DSRetroclPlugin - replog: an error occured while
adding change number 2296384, dn = changenumber=2296384,cn=changelog:
Operations error.
[13/Jul/2015:23:56:50 -0400] retrocl-plugin - retrocl_postob: operation failure
[1]
[14/Jul/2015:06:56:50 -0400] - dn2entry_ext: Failed to get id for
changenumber=2304418,cn=changelog from entryrdn index (-30993)
[14/Jul/2015:06:56:50 -0400] - Operation error fetching
changenumber=2304418,cn=changelog (null), error -30993.
[14/Jul/2015:06:56:50 -0400] DSRetroclPlugin - replog: an error occured while
adding change number 2304418, dn = changenumber=2304418,cn=changelog:
Operations error.
[14/Jul/2015:06:56:50 -0400] retrocl-plugin - retrocl_postob: operation failure
[1]
- eventually enable replication logging: nsslapd-errorlog-level: 8192
On a side note, we get hit with this bug often:
https://www.redhat.com/archives/freeipa-users/2015-July/msg00018.html
(rouge sssd_be processing hammering a replica).
This causes high ns-slapd utilization on the replica and restarting sssd
on the client host immediately fixes the issue. However, in this
case, we're not seeing this behavior.
On 07/13/2015 04:46 PM, Andrew E. Bruno wrote:
We have 3 freeipa-replicas. Centos 7.1.1503, ipa-server 4.1.0-18, and
389-ds 1.3.3.1-16.
Recently, the ns-slapd process on one of our replicas started showing higher
than normal CPU usage. ns-slapd is pegged at high CPU usage more or less
constantly.
Seems very similar to this thread:
https://www.redhat.com/archives/freeipa-users/2015-February/msg00281.html
There are a few errors showing in /var/log/dirsrv/slapd-[domain]/errors (not
sure if these are related):
[13/Jul/2015:02:56:49 -0400] retrocl-plugin - retrocl_postob: operation failure
[1]
[13/Jul/2015:04:11:50 -0400] - dn2entry_ext: Failed to get id for
changenumber=2277387,cn=changelog from entryrdn index (-30993)
[13/Jul/2015:04:11:50 -0400] - Operation error fetching
changenumber=2277387,cn=changelog (null), error -30993.
[13/Jul/2015:04:11:50 -0400] DSRetroclPlugin - replog: an error occured while
adding change number 2277387, dn = changenumber=2277387,cn=changelog:
Operations error.
[13/Jul/2015:04:11:50 -0400] retrocl-plugin - retrocl_postob: operation failure
[1]
[13/Jul/2015:07:41:49 -0400] - Operation error fetching Null DN
(01de36ac-295411e5-b94db2ab-07afbca6), error -30993.
[13/Jul/2015:07:41:49 -0400] - dn2entry_ext: Failed to get id for
changenumber=2281464,cn=changelog from entryrdn index (-30993)
[13/Jul/2015:07:41:49 -0400] - Operation error fetching
changenumber=2281464,cn=changelog (null), error -30993.
[13/Jul/2015:07:41:49 -0400] DSRetroclPlugin - replog: an error occured while
adding change number 2281464, dn = changenumber=2281464,cn=changelog:
Operations error.
[13/Jul/2015:07:41:49 -0400] retrocl-plugin - retrocl_postob: operation failure
[1]
access logs seem to be showing normal activity. Here's the number of open
connections:
# ls -al /proc/`cat /var/run/dirsrv/slapd-[domain].pid`/fd|grep socket|wc -l
62
Note: the other two replicas have much higher open connections (>250) and low
cpu load avgs.
Here's some output of logconv.pl from our most recent access log on the replica
with high cpu load:
Start of Logs: 13/Jul/2015:04:49:18
End of Logs: 13/Jul/2015:10:06:11
Processed Log Time: 5 Hours, 16 Minutes, 53 Seconds
Restarts: 0
Total Connections: 2343
- LDAP Connections: 2120
- LDAPI Connections: 223
- LDAPS Connections: 0
- StartTLS Extended Ops: 45
Secure Protocol Versions:
- TLS1.2 128-bit AES - 45
Peak Concurrent Connections: 22
Total Operations: 111865
Total Results: 111034
Overall Performance: 99.3%
Searches: 95585 (5.03/sec) (301.64/min)
Modifications: 3369 (0.18/sec) (10.63/min)
Adds: 0 (0.00/sec) (0.00/min)
Deletes: 0 (0.00/sec) (0.00/min)
Mod RDNs: 0 (0.00/sec) (0.00/min)
Compares: 0 (0.00/sec) (0.00/min)
Binds: 7082 (0.37/sec) (22.35/min)
Proxied Auth Operations: 0
Persistent Searches: 0
Internal Operations: 0
Entry Operations: 0
Extended Operations: 5317
Abandoned Requests: 416
Smart Referrals Received: 0
VLV Operations: 96
VLV Unindexed Searches: 0
VLV Unindexed Components: 32
SORT Operations: 64
Entire Search Base Queries: 0
Paged Searches: 3882
Unindexed Searches: 0
Unindexed Components: 5
FDs Taken: 2566
FDs Returned: 2643
Highest FD Taken: 249
Broken Pipes: 0
Connections Reset By Peer: 0
Resource Unavailable: 0
Max BER Size Exceeded: 0
Binds: 7082
Unbinds: 2443
- LDAP v2 Binds: 0
- LDAP v3 Binds: 6859
- AUTOBINDs: 223
- SSL Client Binds: 0
- Failed SSL Client Binds: 0
- SASL Binds: 6814
GSSAPI - 6591
EXTERNAL - 223
- Directory Manager Binds: 0
- Anonymous Binds: 6591
- Other Binds: 491
strace timing on the ns-slapd process:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
94.40 0.346659 5977 58 poll
4.10 0.015057 15057 1 restart_syscall
0.91 0.003353 57 59 59 getpeername
0.49 0.001796 150 12 futex
0.10 0.000364 73 5 read
------ ----------- ----------- --------- --------- ----------------
100.00 0.367229 135 59 total
top output (with threads 'H'):
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2879 dirsrv 20 0 3819252 1.962g 11680 R 99.9 3.1 8822:10 ns-slapd
2895 dirsrv 20 0 3819252 1.962g 11680 R 34.1 3.1 115:10.62 ns-slapd
2889 dirsrv 20 0 3819252 1.962g 11680 R 2.4 3.1 115:34.42 ns-slapd
2917 dirsrv 20 0 3819252 1.962g 11680 S 2.4 3.1 115:26.87 ns-slapd
2898 dirsrv 20 0 3819252 1.962g 11680 S 2.1 3.1 116:33.12 ns-slapd
2904 dirsrv 20 0 3819252 1.962g 11680 S 2.1 3.1 115:08.56 ns-slapd
2892 dirsrv 20 0 3819252 1.962g 11680 S 1.8 3.1 115:33.04 ns-slapd
2897 dirsrv 20 0 3819252 1.962g 11680 R 1.8 3.1 114:54.28 ns-slapd
2914 dirsrv 20 0 3819252 1.962g 11680 R 1.8 3.1 116:03.35 ns-slapd
2907 dirsrv 20 0 3819252 1.962g 11680 S 1.5 3.1 115:42.25 ns-slapd
2910 dirsrv 20 0 3819252 1.962g 11680 R 1.5 3.1 116:01.99 ns-slapd
2870 dirsrv 20 0 3819252 1.962g 11680 R 1.2 3.1 611:30.22 ns-slapd
2890 dirsrv 20 0 3819252 1.962g 11680 S 1.2 3.1 115:18.25 ns-slapd
2891 dirsrv 20 0 3819252 1.962g 11680 S 1.2 3.1 115:22.24 ns-slapd
2899 dirsrv 20 0 3819252 1.962g 11680 R 1.2 3.1 116:11.85 ns-slapd
2888 dirsrv 20 0 3819252 1.962g 11680 S 0.9 3.1 114:51.19 ns-slapd
2896 dirsrv 20 0 3819252 1.962g 11680 R 0.9 3.1 115:46.84 ns-slapd
2915 dirsrv 20 0 3819252 1.962g 11680 S 0.9 3.1 115:49.34 ns-slapd
2887 dirsrv 20 0 3819252 1.962g 11680 R 0.6 3.1 115:49.85 ns-slapd
2894 dirsrv 20 0 3819252 1.962g 11680 S 0.6 3.1 115:58.02 ns-slapd
2911 dirsrv 20 0 3819252 1.962g 11680 S 0.6 3.1 116:22.84 ns-slapd
2913 dirsrv 20 0 3819252 1.962g 11680 S 0.6 3.1 114:43.56 ns-slapd
ns-slapd stays pegged >99%. Trying to figure out what ns-slapd is doing? Any
pointers on where else to look?
Thanks in advance.
--Andrew
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project
