Hi Rich,
Is it possible that you have some trailing whitespace at the end of
inetOrgPerson?
That was it – I must have picked up a CR when cutting and pasting from Outlook. Have
corrected the entry and will see how the identity manager app does with the aggregation
queries, around lunch 12pm. I’ll let you know how it goes.
Mark: Can you paste the actual index entry from your dse.ldif here?
dn: cn=objectclass,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config
objectClass: top
objectClass: nsIndex
cn: objectclass
nsSystemIndex: true
nsIndexType: eq
creatorsName: cn=ldbm database,cn=plugins,cn=config
modifiersName: cn=directory manager
createTimestamp: 20130613205147Z
modifyTimestamp: 20141211181523Z
nsIndexIDListScanLimit: limit=-1 type=eq flags=AND values=inetOrgPerson
Trev
From: Rich Megginson <rmeggins@redhat.com<mailto:rmeggins@redhat.com>>
Reply-To:
"389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>"
<389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>>
Date: Thursday, December 11, 2014 at 10:00 AM
To:
"389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>"
<389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>>
Subject: Re: [389-users] 389-ds and Multi CPU's
On 12/11/2014 10:49 AM, Mark Reynolds wrote:
On 12/11/2014 12:43 PM, Rich Megginson wrote:
On 12/11/2014 10:03 AM, Fong, Trevor wrote:
Hi Mark,
Sorry for the lack of response – I was off yesterday.
There were no errors when I made the updates, but when I restated the dirsrv’s, I got the
following error:
[10/Dec/2014:23:52:20 -0800] - 389-Directory/1.2.11.15 B2014.300.2010 starting up
[10/Dec/2014:23:52:20 -0800] - attr_index_config: from ldbm instance init: Failed to parse
idscanlimit info: 53:attr_index_parse_idlistsize: value inetOrgPerson
Is it possible that you have some trailing whitespace at the end of inetOrgPerson?
violates syntax for attribute objectClass
Does it work if you use "inetorgperson" (that is, all lower case) instead?
It works for me.
ldapmodify -D ....
dn: cn=objectclass,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config
changetype: modify
replace: nsIndexIDListScanLimit
nsIndexIDListScanLimit: limit=-1 type=eq values=inetOrgPerson
nsIndexIDListScanLimit: limit=-1 type=eq flags=AND values=inetOrgPerson
modifying entry "cn=objectclass,cn=index,cn=userRoot,cn=ldbm
database,cn=plugins,cn=config"
^C
[root@localhost etc]# restart-dirsrv
Restarting instance "localhost"
Warning: Unit file of dirsrv@localhost.service<mailto:dirsrv@localhost.service>
changed on disk, 'systemctl daemon-reload' recommended.
Warning: Unit file of dirsrv@localhost.service<mailto:dirsrv@localhost.service>
changed on disk, 'systemctl daemon-reload' recommended.
[root@localhost etc]# tail /var/log/dirsrv/slapd-localhost/errors
[11/Dec/2014:12:45:51 -0500] - slapd shutting down - closing down internal subsystems and
plugins
[11/Dec/2014:12:45:51 -0500] - Waiting for 4 database threads to stop
[11/Dec/2014:12:45:52 -0500] - All database threads now stopped
[11/Dec/2014:12:45:52 -0500] - slapd shutting down - freed 1 work q stack objects - freed
2 op stack objects
[11/Dec/2014:12:45:52 -0500] - slapd stopped.
[11/Dec/2014:12:45:53 -0500] - 389-Directory/1.3.4.a1.gitfb22b38 B2014.345.1437 starting
up
[11/Dec/2014:12:45:53 -0500] - I'm resizing my cache now...cache was 549754 and is now
439803
[11/Dec/2014:12:45:53 -0500] - slapi_search_internal_set_pb: NULL parameter
[11/Dec/2014:12:45:53 -0500] - allow_operation: component identity is NULL
[11/Dec/2014:12:45:53 -0500] - slapd started. Listening on All Interfaces port 389 for
LDAP requests
Can you paste the actual index entry from your dse.ldif here?
Thanks,
Mark
Trev
From: Mark Reynolds <mareynol@redhat.com<mailto:mareynol@redhat.com>>
Reply-To: "mreynolds@redhat.com<mailto:mreynolds@redhat.com>"
<mreynolds@redhat.com<mailto:mreynolds@redhat.com>>
Date: Tuesday, December 9, 2014 at 3:21 PM
To: Trevor Fong <trevor.fong@ubc.ca<mailto:trevor.fong@ubc.ca>>,
"mreynolds@redhat.com<mailto:mreynolds@redhat.com>"
<mreynolds@redhat.com<mailto:mreynolds@redhat.com>>,
"389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>"
<389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>>
Subject: Re: [389-users] 389-ds and Multi CPU's
On 12/09/2014 05:58 PM, Fong, Trevor wrote:
Hi Mark,
I’ve afraid adding nsIndexIDListScanLimit to cn=objectclass,cn=index,cn=userRoot,cn=ldbm
database,cn=plugins,cn=config doesn’t seem to have any effect. Did this:
dn: cn=objectclass,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config
changetype: modify
add: nsIndexIDListScanLimit
nsIndexIDListScanLimit: limit=-1 type=eq values=inetOrgPerson
Hmm that's very strange, try this:
dn: cn=objectclass,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config
changetype: modify
replace: nsIndexIDListScanLimit
nsIndexIDListScanLimit: limit=-1 type=eq values=inetOrgPerson
nsIndexIDListScanLimit: limit=-1 type=eq flags=AND values=inetOrgPerson
Also, is userRoot the mapping tree that refers to your "dc=<your dc>"? I
just want to make sure we are updating the correct objectclass index configuration entry.
This should get rid of those unindexed searches. Is there anything in the 389 DS errors
log regarding these settings?
Thanks,
Mark
CPU was still in the 70’s. Logconv.pl output looks much the same. Follows.
Thanks a lot,
Trev
Total Log Lines Analysed: 424930
----------- Access Log Output ------------
Start of Logs: 09/Dec/2014:11:20:00
End of Logs: 09/Dec/2014:14:09:20
Processed Log Time: 2 Hours, 49 Minutes, 20 Seconds
Restarts: 0
Total Connections: 3909
- StartTLS Connections: 0
- LDAPS Connections: 3534
- LDAPI Connections: 0
Peak Concurrent Connections: 6
Total Operations: 61321
Total Results: 61321
Overall Performance: 100.0%
Searches: 58178 (5.73/sec) (343.57/min)
Modifications: 266 (0.03/sec) (1.57/min)
Adds: 93 (0.01/sec) (0.55/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: 2570 (0.25/sec) (15.18/min)
Proxied Auth Operations: 0
Persistent Searches: 0
Internal Operations: 0
Entry Operations: 0
Extended Operations: 214
Abandoned Requests: 0
Smart Referrals Received: 0
VLV Operations: 0
VLV Unindexed Searches: 0
VLV Unindexed Components: 0
SORT Operations: 1
Entire Search Base Queries: 0
Paged Searches: 546
Unindexed Searches: 1
Unindexed Components: 545
Unindexed Search #1 (notes=A)
- Date/Time: 09/Dec/2014:13:19:05
- Connection Number: 348121
- Operation Number: 2
- Etime: 0
- Nentries: 100
- IP Address: 10.7.8.105
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
Unindexed Component #1 (notes=U)
- Date/Time: 09/Dec/2014:11:30:16
- Connection Number: 344719
- Operation Number: 101
- Etime: 0
- Nentries: 100
- IP Address: Unknown_Host
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
Unindexed Component #2 (notes=U)
- Date/Time: 09/Dec/2014:11:31:47
- Connection Number: 344719
- Operation Number: 105
- Etime: 0
- Nentries: 100
- IP Address: Unknown_Host
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
…<snip>
Unindexed Component #545 (notes=U)
- Date/Time: 09/Dec/2014:13:19:21
- Connection Number: 348121
- Operation Number: 9
- Etime: 1
- Nentries: 100
- IP Address: 10.7.8.105
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
FDs Taken: 3909
FDs Returned: 3910
Highest FD Taken: 257
Broken Pipes: 0
Connections Reset By Peer: 0
Resource Unavailable: 0
Max BER Size Exceeded: 0
Binds: 2570
Unbinds: 1470
- LDAP v2 Binds: 0
- LDAP v3 Binds: 2570
- AUTOBINDs: 0
- SSL Client Binds: 0
- Failed SSL Client Binds: 0
- SASL Binds: 0
- Directory Manager Binds: 1170
- Anonymous Binds: 0
- Other Binds: 1400
----- Connection Latency Details -----
(in seconds) <=1 2 3 4-5 6-10 11-15 >15
--------------------------------------------------------------------------
(# of connections) 3783 2 2 22 10 2 89
----- Current Open Connection IDs -----
Conn Number: 348500 (10.7.127.250)
Conn Number: 348440 (10.7.127.250)
----- Errors -----
err=0 59285 Successful Operations
err=32 1017 No Such Object
err=53 1017 Unwilling To Perform
err=49 2 Invalid Credentials (Bad Password)
----- Top 20 Failed Logins ------
2 uid=elainez,ou=employees,dc=<our dc>
From the IP address(s) :
2 10.7.8.104
----- Total Connection Codes -----
U1 1470 Cleanly Closed Connections
B1 1089 Bad Ber Tag Encountered
----- Top 20 Clients -----
Number of Clients: 15
[1] Client: 10.20.220.16
1170 - Connections
1170 - U1 (Cleanly Closed Connections)
[2] Client: 137.82.5.97
1017 - Connections
1017 - B1 (Bad Ber Tag Encountered)
[3] Client: 142.103.218.107
674 - Connections
[4] Client: 142.103.218.106
674 - Connections
[5] Client: 10.7.127.250
58 - Connections
54 - U1 (Cleanly Closed Connections)
[6] Client: 10.7.0.52
53 - Connections
53 - U1 (Cleanly Closed Connections)
[7] Client: 142.103.106.142
40 - Connections
40 - U1 (Cleanly Closed Connections)
[8] Client: 142.103.106.135
38 - Connections
38 - U1 (Cleanly Closed Connections)
[9] Client: 127.0.0.1
36 - Connections
35 - B1 (Bad Ber Tag Encountered)
1 - U1 (Cleanly Closed Connections)
[10] Client: 142.103.149.136
34 - Connections
33 - B1 (Bad Ber Tag Encountered)
1 - U1 (Cleanly Closed Connections)
[11] Client: 142.103.106.143
33 - Connections
33 - U1 (Cleanly Closed Connections)
[12] Client: 142.103.106.145
31 - Connections
31 - U1 (Cleanly Closed Connections)
[13] Client: 142.103.106.141
28 - Connections
28 - U1 (Cleanly Closed Connections)
[14] Client: 10.7.8.104
12 - Connections
8 - U1 (Cleanly Closed Connections)
4 - B1 (Bad Ber Tag Encountered)
[15] Client: 10.7.8.105
11 - Connections
11 - U1 (Cleanly Closed Connections)
----- Top 20 Bind DN's -----
Number of Unique Bind DN's: 11
1240 cn=directory manager
1017 cn=bill fisher,ou=people,dc=dartware,dc=com
206 uid=<service accoount 1>
53 cn=replication manager,cn=config
34 uid=<service account 2>
6 uid=rogermo,ou=employees,dc=<our dc>
6 uid=elainez,ou=employees,dc=<our dc>
2 uid=rwong,ou=employees,dc=<our dc>
2 uid=steve0d6,ou=employees,dc=<our dc>
2 uid=huynhh,ou=employees,dc=<our dc>
2 uid=robg,ou=employees,dc=<our dc>
----- Top 20 Search Bases -----
Number of Unique Search Bases: 9
55737 ou=groups,dc=<our dc>
1017 ou=people,dc=dartware,dc=com
766 ou=employees,dc=<our dc>
391 ou=people,dc=<our dc>
140 cn=mapping tree,cn=config
121 root dse
2 uid=ark826,ou=employees,dc=<our dc>
2 uid=emilygib,ou=employees,dc=<our dc>
2 uid=kgg39500,ou=employees,dc=<our dc>
----- Top 20 Search Filters -----
Number of Unique Search Filters: 31129
1017 (cn=bill fisher)
546 (&(objectclass=inetorgperson))
124 (objectclass=*)
35 (cn=eldap3*)
35 (cn=eldap5*)
35 (cn=eldap4*)
35 (cn=eldap2*)
5
(&(objectclass=groupofnames)(member=uid=elainez,ou=employees,dc=<our dc>))
4 (|(cn=elainez)(uid=elainez)(mail=elainez))
4 (&(objectclass=inetorgperson)(ubceducwlloginkey=<login key 1>))
4 (&(uid=dkavoura))
4 (&(uid=umashank))
4
(&(objectclass=groupofnames)(member=uid=rogermo,ou=employees,dc=<our dc>))
4 (&(uid=joshb11))
4 (&(uid=joaweg))
4 (&(objectclass=inetorgperson)(ubceducwlloginkey=<login key 2>))
3
(&(objectclass=groupofnames)(member=uid=dentonel,ou=employees,dc=<our dc>))
3 (&(objectclass=groupofnames)(member=uid=wexler,ou=employees,dc=<our
dc>))
3
(&(objectclass=groupofnames)(member=uid=marizulu,ou=employees,dc=<our dc>))
3
(&(objectclass=groupofnames)(member=uid=agurjal,ou=employees,dc=<our dc>))
----- Top 20 Most Frequent etimes -----
53984 etime=0
7319 etime=1
11 etime=2
4 etime=8
1 etime=142
1 etime=159
1 etime=9
----- Top 20 Longest etimes -----
etime=159 1
etime=142 1
etime=9 1
etime=8 4
etime=2 11
etime=1 7319
etime=0 53984
----- Top 20 Largest nentries -----
nentries=100 544
nentries=36 2
nentries=7 2
nentries=6 6
nentries=5 34
nentries=4 153
nentries=3 1182
nentries=2 4697
nentries=1 41333
nentries=0 10225
----- Top 20 Most returned nentries -----
41333 nentries=1
10225 nentries=0
4697 nentries=2
1182 nentries=3
544 nentries=100
153 nentries=4
34 nentries=5
6 nentries=6
2 nentries=36
2 nentries=7
----- Extended Operations -----
107 2.16.840.1.113730.3.5.12 DS90 Start Replication Request
107 2.16.840.1.113730.3.5.5 End Replication Request (incremental update)
----- Top 20 Most Requested Attributes -----
54570 1.1
2498 All Attributes
1126 o
954 description
954 givenName
954 ubcEduCwlPUID
954 uid
954 cn
954 displayName
954 employeeNumber
954 mail
954 nsAccountLock
954 objectClass
954 sn
563 businessCategory
563 employeeType
563 facsimileTelephoneNumber
563 groups
563 homePostalAddress
563 l
----- Recommendations -----
1. You have unindexed searches, this can be caused from a search on an unindexed
attribute, or your returned results exceeded the allidsthreshold. Unindexed searches are
not recommended. To refuse unindexed searches, switch 'nsslapd-require-index' to
'on' under your database entry (e.g. cn=UserRoot,cn=ldbm
database,cn=plugins,cn=config).
2. You have unindexed components, this can be caused from a search on an unindexed
attribute, or your returned results exceeded the allidsthreshold. Unindexed components
are not recommended. To refuse unindexed searches, switch 'nsslapd-require-index'
to 'on' under your database entry (e.g. cn=UserRoot,cn=ldbm
database,cn=plugins,cn=config).
3. You have a significant difference between binds and unbinds. You may want to
investigate this difference.
4. You have a high number of Directory Manager binds. The Directory Manager account
should only be used under certain circumstances. Avoid using this account for client
applications.
Cleaning up temp files...
Done.
From: Mark Reynolds <mareynol@redhat.com<mailto:mareynol@redhat.com>>
Reply-To: "mreynolds@redhat.com<mailto:mreynolds@redhat.com>"
<mreynolds@redhat.com<mailto:mreynolds@redhat.com>>
Date: Tuesday, December 9, 2014 at 9:33 AM
To: Trevor Fong <trevor.fong@ubc.ca<mailto:trevor.fong@ubc.ca>>,
"mreynolds@redhat.com<mailto:mreynolds@redhat.com>"
<mreynolds@redhat.com<mailto:mreynolds@redhat.com>>,
"389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>"
<389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>>
Subject: Re: [389-users] 389-ds and Multi CPU's
On 12/09/2014 12:14 PM, Fong, Trevor wrote:
Hi Mark,
Oops – sorry about the Mike thing! I sit beside a Mike :p
No worries :-)
So your high CPU is most likely coming from your unindexed searches.
The version you are on should support the new per index idlistscanlimit, so try this:
Note, this this is just an example, your objectclass entry might have a different DN
(userRoot might be something else in your deployment)
ldapmodify ...
dn: cn=objectclass,cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config
changetype: modify
replace: nsIndexIDListScanLimit
nsIndexIDListScanLimit: limit=-1 type=eq values=inetOrgPerson
Depending on your results we might tweak the nsIndexIDListScanLimit value again. This
change should take effect immediately - no need to restart.
Let me know how it goes.
Thanks,
Mark
Oh – no notes in that search, but there are notes in the preceding and subsequent
searches. It looks like it returns the first 100 results then searches for groupOfNames
for each of those users, and then repeats until all 30,000 users is done:
08/Dec/2014:07:08:04 -0800] conn=130261 fd=64 slot=64 SSL connection from <ip addr
1> to <ip addr 2>
[08/Dec/2014:07:08:04 -0800] conn=130261 SSL 256-bit AES
[08/Dec/2014:07:08:04 -0800] conn=130261 op=0 BIND dn="<service account>"
method=128 version=3
[08/Dec/2014:07:08:04 -0800] conn=130261 op=0 RESULT err=0 tag=97 nentries=0 etime=0
dn="<service account>"
[08/Dec/2014:07:08:04 -0800] conn=130261 op=1 SRCH base="" scope=0
filter="(objectClass=*)" attrs="supportedControl"
[08/Dec/2014:07:08:04 -0800] conn=130261 op=1 RESULT err=0 tag=101 nentries=1 etime=0
[08/Dec/2014:07:08:04 -0800] conn=130261 op=2 SRCH base="ou=EMPLOYEES,dc=<our
dc>" scope=2 filter="(&(objectClass=inetOrgPerson))"
attrs="businessCategory carLicense cn departmentNumber description
destinationIndicator displayName distinguishedName employeeNumber employeeType
facsimileTelephoneNumber givenName groups homePhone homePostalAddress initials
internationalISDNNumber l mail manager mobile o objectClass o ou pager
physicalDeliveryOfficeName postOfficeBox postalAddress postalCode preferredDeliveryMethod
preferredLanguage registeredAddress roomNumber secretary seeAlso sn st street
telephoneNumber teletexTerminalIdentifier telexNumber title ubcEduCwlPUID uid
nsAccountLock passwordRetryCount"
[08/Dec/2014:07:08:04 -0800] conn=130261 op=2 SORT cn (*)
[08/Dec/2014:07:08:04 -0800] conn=130261 op=2 RESULT err=0 tag=101 nentries=100 etime=0
notes=P,A
[08/Dec/2014:07:08:04 -0800] conn=130262 fd=83 slot=83 SSL connection from <ip addr
1> to <ip addr 2>
[08/Dec/2014:07:08:04 -0800] conn=130262 SSL 256-bit AES
[08/Dec/2014:07:08:04 -0800] conn=130262 op=0 BIND dn="<service account>"
method=128 version=3
[08/Dec/2014:07:08:04 -0800] conn=130262 op=0 RESULT err=0 tag=97 nentries=0 etime=0
dn="<service account>"
[08/Dec/2014:07:08:04 -0800] conn=130262 op=1 SRCH base="ou=GROUPS,dc=<our
dc>" scope=2
filter="(&(objectClass=groupOfNames)(member=uid=<login_x>,ou=EMPLOYEES,dc=<our
dc>))" attrs="1.1"
[08/Dec/2014:07:08:04 -0800] conn=130262 op=1 RESULT err=0 tag=101 nentries=5 etime=0
… <snip>
[08/Dec/2014:07:08:05 -0800] conn=130262 op=100 SRCH base="ou=GROUPS,dc=<our
dc>" scope=2
filter="(&(objectClass=groupOfNames)(member=uid=<login_x+100>,ou=EMPLOYEES,dc=<our
dc>))" attrs="1.1"
[08/Dec/2014:07:08:05 -0800] conn=130262 op=100 RESULT err=0 tag=101 nentries=3 etime=0
[08/Dec/2014:07:08:05 -0800] conn=130261 op=3 SRCH base="ou=EMPLOYEES,dc=<our
dc>" scope=2 filter="(&(objectClass=inetOrgPerson))"
attrs="businessCategory carLicense cn departmentNumber description
destinationIndicator displayName distinguishedName employeeNumber employeeType
facsimileTelephoneNumber givenName groups homePhone homePostalAddress initials
internationalISDNNumber l mail manager mobile o objectClass o ou pager
physicalDeliveryOfficeName postOfficeBox postalAddress postalCode preferredDeliveryMethod
preferredLanguage registeredAddress roomNumber secretary seeAlso sn st street
telephoneNumber teletexTerminalIdentifier telexNumber title ubcEduCwlPUID uid
nsAccountLock passwordRetryCount"
… <snip>
[08/Dec/2014:07:08:05 -0800] conn=130261 op=3 RESULT err=0 tag=101 nentries=100 etime=0
notes=U,P
Oh cool – I didn’t know about logconv.pl! Output follows.
Thanks again,
Trev
Total Log Lines Analysed: 799338
----------- Access Log Output ------------
Start of Logs: 08/Dec/2014:05:56:33
End of Logs: 08/Dec/2014:10:31:46
Processed Log Time: 4 Hours, 35 Minutes, 13 Seconds
Restarts: 0
Total Connections: 87873
- StartTLS Connections: 0
- LDAPS Connections: 87265
- LDAPI Connections: 0
Peak Concurrent Connections: 34
Total Operations: 227313
Total Results: 227314
Overall Performance: 100.0%
Searches: 109051 (6.60/sec) (396.24/min)
Modifications: 28121 (1.70/sec) (102.18/min)
Adds: 69 (0.00/sec) (0.25/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: 85702 (5.19/sec) (311.40/min)
Proxied Auth Operations: 0
Persistent Searches: 0
Internal Operations: 0
Entry Operations: 0
Extended Operations: 4370
Abandoned Requests: 0
Smart Referrals Received: 0
VLV Operations: 0
VLV Unindexed Searches: 0
VLV Unindexed Components: 0
SORT Operations: 3
Entire Search Base Queries: 0
Paged Searches: 505
Unindexed Searches: 2
Unindexed Components: 502
Unindexed Search #1 (notes=A)
- Date/Time: 08/Dec/2014:10:30:12
- Connection Number: 215422
- Operation Number: 2
- Etime: 1
- Nentries: 100
- IP Address: 10.7.8.105
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
Unindexed Search #2 (notes=A)
- Date/Time: 08/Dec/2014:07:08:04
- Connection Number: 130261
- Operation Number: 2
- Etime: 0
- Nentries: 100
- IP Address: 10.7.8.105
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
Unindexed Component #1 (notes=U)
- Date/Time: 08/Dec/2014:05:56:45
- Connection Number: 129083
- Operation Number: 117
- Etime: 0
- Nentries: 100
- IP Address: Unknown_Host
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
Unindexed Component #2 (notes=U)
- Date/Time: 08/Dec/2014:05:57:10
- Connection Number: 129083
- Operation Number: 122
- Etime: 0
- Nentries: 100
- IP Address: Unknown_Host
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
…<snip>
Unindexed Component #502 (notes=U)
- Date/Time: 08/Dec/2014:10:30:47
- Connection Number: 215422
- Operation Number: 3
- Etime: 0
- Nentries: 100
- IP Address: 10.7.8.105
- Search Base: ou=employees,dc=<our dc>
- Search Scope: 2 (subtree)
- Search Filter: (&(objectclass=inetorgperson))
FDs Taken: 87873
FDs Returned: 87863
Highest FD Taken: 275
Broken Pipes: 0
Connections Reset By Peer: 0
Resource Unavailable: 0
Max BER Size Exceeded: 0
Binds: 85702
Unbinds: 83924
- LDAP v2 Binds: 0
- LDAP v3 Binds: 85702
- AUTOBINDs: 0
- SSL Client Binds: 0
- Failed SSL Client Binds: 0
- SASL Binds: 0
- Directory Manager Binds: 0
- Anonymous Binds: 0
- Other Binds: 85702
----- Connection Latency Details -----
(in seconds) <=1 2 3 4-5 6-10 11-15 >15
--------------------------------------------------------------------------
(# of connections) 87553 169 27 18 5 2 89
----- Current Open Connection IDs -----
Conn Number: 201302 (10.7.127.250)
Conn Number: 217063 (10.7.8.105)
Conn Number: 217064 (10.7.8.105)
Conn Number: 217061 (10.7.8.105)
Conn Number: 132242 (10.7.0.52)
Conn Number: 196007 (10.7.127.250)
Conn Number: 196107 (10.7.127.250)
Conn Number: 215425 (10.7.8.105)
Conn Number: 217060 (10.7.8.105)
Conn Number: 215422 (10.7.8.105)
Conn Number: 207139 (10.7.127.250)
Conn Number: 217062 (10.7.8.105)
----- Errors -----
err=0 224008 Successful Operations
err=32 1652 No Such Object
err=53 1652 Unwilling To Perform
err=49 1 Invalid Credentials (Bad Password)
err=65 1 Objectclass Violation
----- Top 20 Failed Logins ------
1 uid=ehannah,ou=employees,dc=<our dc>
From the IP address(s) :
1 10.7.127.250
----- Total Connection Codes -----
U1 83924 Cleanly Closed Connections
B1 1749 Bad Ber Tag Encountered
----- Top 20 Clients -----
Number of Clients: 13
[1] Client: 10.7.8.105
83638 - Connections
83631 - U1 (Cleanly Closed Connections)
[2] Client: 137.82.5.97
1652 - Connections
1652 - B1 (Bad Ber Tag Encountered)
[3] Client: 142.103.218.107
1095 - Connections
[4] Client: 142.103.218.106
1094 - Connections
[5] Client: 10.7.127.250
112 - Connections
106 - U1 (Cleanly Closed Connections)
1 - B1 (Bad Ber Tag Encountered)
[6] Client: 127.0.0.1
57 - Connections
55 - B1 (Bad Ber Tag Encountered)
2 - U1 (Cleanly Closed Connections)
[7] Client: 142.103.149.136
55 - Connections
41 - B1 (Bad Ber Tag Encountered)
14 - U1 (Cleanly Closed Connections)
[8] Client: 10.7.0.52
51 - Connections
50 - U1 (Cleanly Closed Connections)
[9] Client: 142.103.106.141
29 - Connections
29 - U1 (Cleanly Closed Connections)
[10] Client: 142.103.106.143
28 - Connections
28 - U1 (Cleanly Closed Connections)
[11] Client: 142.103.106.145
23 - Connections
23 - U1 (Cleanly Closed Connections)
[12] Client: 142.103.106.135
23 - Connections
23 - U1 (Cleanly Closed Connections)
[13] Client: 142.103.106.142
16 - Connections
16 - U1 (Cleanly Closed Connections)
----- Top 20 Bind DN's -----
Number of Unique Bind DN's: 18
83795 uid=eldap-svciiq,ou=service
accounts,ou=eldap,ou=services,dc=id,dc=ubc,dc=ca
1652 cn=bill fisher,ou=people,dc=dartware,dc=com
112 cn=directory manager
55 uid=eldap-svcvpnsync,ou=service
accounts,ou=eldap,ou=services,dc=id,dc=ubc,dc=ca
51 cn=replication manager,cn=config
6 uid=alexnam,ou=employees,dc=<our dc>
4 uid=priyanth,ou=employees,dc=<our dc>
4 uid=arsuther,ou=employees,dc=<our dc>
4 uid=huynhh,ou=employees,dc=<our dc>
3 uid=ehannah,ou=employees,dc=<our dc>
2 uid=andyfehr,ou=employees,dc=<our dc>
2 uid=bullfrog,ou=employees,dc=<our dc>
2 uid=eddiefok,ou=employees,dc=<our dc>
2 uid=elyoung,ou=employees,dc=<our dc>
2 uid=elainez,ou=employees,dc=<our dc>
2 uid=flokam,ou=employees,dc=<our dc>
2 uid=mailvaga,ou=employees,dc=<our dc>
2 uid=sjones,ou=employees,dc=<our dc>
----- Top 20 Search Bases -----
Number of Unique Search Bases: 27876
78174 ou=groups,dc=<our dc>
1652 ou=people,dc=dartware,dc=com
676 ou=employees,dc=<our dc>
312 ou=people,dc=<our dc>
220 cn=mapping tree,cn=config
124 root dse
13 cn=idm-status-activeemployees,ou=idm,ou=role,ou=groups,dc=<our dc>
3 uid=jbartnik,ou=employees,dc=<our dc>
2 uid=rodsprus,ou=employees,dc=<our dc>
2 uid=zanottic,ou=employees,dc=<our dc>
2 uid=ttucker,ou=employees,dc=<our dc>
2 uid=dbilczuk,ou=employees,dc=<our dc>
2 uid=phys2012,ou=employees,dc=<our dc>
2 uid=ydeng,ou=employees,dc=<our dc>
2 uid=natcrang,ou=employees,dc=<our dc>
2 uid=lillaroy,ou=employees,dc=<our dc>
2 uid=wpr8847,ou=employees,dc=<our dc>
1 uid=ap8040,ou=employees,dc=<our dc>
1 uid=asr5,ou=employees,dc=<our dc>
1 uid=belzberg,ou=employees,dc=<our dc>
----- Top 20 Search Filters -----
Number of Unique Search Filters: 30968
28016 (objectclass=*)
1652 (cn=bill fisher)
504 (&(objectclass=inetorgperson))
55 (cn=eldap3*)
55 (cn=eldap5*)
55 (cn=eldap4*)
55 (cn=eldap2*)
6
(&(objectclass=groupofnames)(member=uid=alexnam,ou=employees,dc=<our dc>))
5
(&(objectclass=groupofnames)(member=uid=ehannah,ou=employees,dc=<our dc>))
5
(&(objectclass=groupofnames)(member=uid=priyanth,ou=employees,dc=<our dc>))
5
(&(objectclass=groupofnames)(member=uid=arsuther,ou=employees,dc=<our dc>))
4 (&(objectclass=groupofnames)(member=uid=ydeng,ou=employees,dc=<our
dc>))
4 (&(objectclass=inetorgperson)(ubceducwlloginkey=<login key 1>))
4
(&(objectclass=groupofnames)(member=uid=elyoung,ou=employees,dc=<our dc>))
4
(&(objectclass=groupofnames)(member=uid=zanottic,ou=employees,dc=<our dc>))
4 (&(uid=devlin11))
4 (&(objectclass=groupofnames)(member=uid=huynhh,ou=employees,dc=<our
dc>))
4 (&(objectclass=inetorgperson)(ubceducwlloginkey=<login key 2>))
4
(&(objectclass=groupofnames)(member=uid=lillaroy,ou=employees,dc=<our dc>))
4
(&(objectclass=groupofnames)(member=uid=rodsprus,ou=employees,dc=<our dc>))
----- Top 20 Most Frequent etimes -----
219090 etime=0
8202 etime=1
20 etime=2
1 etime=147
1 etime=135
----- Top 20 Longest etimes -----
etime=147 1
etime=135 1
etime=2 20
etime=1 8202
etime=0 219090
----- Top 20 Largest nentries -----
nentries=100 502
nentries=34 1
nentries=27 1
nentries=26 1
nentries=7 3
nentries=6 9
nentries=5 85
nentries=4 334
nentries=3 1957
nentries=2 6701
nentries=1 85038
nentries=0 14420
----- Top 20 Most returned nentries -----
85038 nentries=1
14420 nentries=0
6701 nentries=2
1957 nentries=3
502 nentries=100
334 nentries=4
85 nentries=5
9 nentries=6
3 nentries=7
1 nentries=26
1 nentries=27
1 nentries=34
----- Extended Operations -----
2185 2.16.840.1.113730.3.5.12 DS90 Start Replication Request
2185 2.16.840.1.113730.3.5.5 End Replication Request (incremental update)
----- Top 20 Most Requested Attributes -----
78174 1.1
56799 o
28712 description
28712 cn
28712 nsAccountLock
28711 givenName
28711 ubcEduCwlPUID
28711 uid
28711 displayName
28711 employeeNumber
28711 mail
28711 objectClass
28711 sn
28400 ou
28400 passwordRetryCount
28400 distinguishedName
28399 businessCategory
28399 employeeType
28399 facsimileTelephoneNumber
28399 groups
----- Recommendations -----
1. You have unindexed searches, this can be caused from a search on an unindexed
attribute, or your returned results exceeded the allidsthreshold. Unindexed searches are
not recommended. To refuse unindexed searches, switch 'nsslapd-require-index' to
'on' under your database entry (e.g. cn=UserRoot,cn=ldbm
database,cn=plugins,cn=config).
2. You have unindexed components, this can be caused from a search on an unindexed
attribute, or your returned results exceeded the allidsthreshold. Unindexed components
are not recommended. To refuse unindexed searches, switch 'nsslapd-require-index'
to 'on' under your database entry (e.g. cn=UserRoot,cn=ldbm
database,cn=plugins,cn=config).
Cleaning up temp files...
Done.
From: Mark Reynolds <mareynol@redhat.com<mailto:mareynol@redhat.com>>
Reply-To: "mreynolds@redhat.com<mailto:mreynolds@redhat.com>"
<mreynolds@redhat.com<mailto:mreynolds@redhat.com>>
Date: Tuesday, December 9, 2014 at 7:25 AM
To:
"389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>"
<389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>>,
Trevor Fong <trevor.fong@ubc.ca<mailto:trevor.fong@ubc.ca>>
Subject: Re: [389-users] 389-ds and Multi CPU's
On 12/08/2014 05:43 PM, Fong, Trevor wrote:
Hi Mike,
It's Mark :-) I get that a lot for some reason.
Thanks for the reply. The typical result of the result is:
[08/Dec/2014:07:08:04 -0800] conn=130262 op=1 RESULT err=0 tag=101 nentries=5 etime=0
Yeah this looks fine.
There are no notes=A/notes=U in the results.
Do you mean in the entire access log, or just for that search?
Can you run logconv.pl and post the results? "logconv.pl -V <access
logs>"
Thanks Trevor,
Mark
Objectclass and member are both indexed.
There were 30,000-odd searches on conn=130262, which took 34 mins.
Thanks,
Trev
From: Mark Reynolds <mareynol@redhat.com<mailto:mareynol@redhat.com>>
Reply-To: "mreynolds@redhat.com<mailto:mreynolds@redhat.com>"
<mreynolds@redhat.com<mailto:mreynolds@redhat.com>>
Date: Monday, December 8, 2014 at 11:29 AM
To:
"389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>"
<389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>>,
Trevor Fong <trevor.fong@ubc.ca<mailto:trevor.fong@ubc.ca>>
Subject: Re: [389-users] 389-ds and Multi CPU's
On 12/08/2014 02:08 PM, Fong, Trevor wrote:
Hi Everyone,
We’ve inherited a 389-ds system (1.2.11.15-48.el6_6) that is running on a VM provisioned
with a single CPU. We have been experiencing high CPU with a client that connects with a
single connection, and then runs large amounts of queries of the form:
SRCH base="ou=GROUPS,dc=<our dc>" scope=2
filter="(&(objectClass=groupOfNames)(member=uid=<loginname>,ou=EMPLOYEES,<our
dc>))" attrs=“1.1"
Trevor,
From the access log, what is the result of this search? etime? It
there a notes=U/notes=A in the result? It could be an unindexed search which would cause
the high CPU.
Thanks,
Mark
We’re wondering if adding extra CPU’s to the vm will make things better. The original
engineer noted that at the time of implementation, he had come across some notes that
indicated that the underlying process was single threaded and adding extra CPU’s would not
make any improvement; in fact, on heavily loaded vm infrastructure like ours, may make
things worse as the the vm would have to wait for the CPU to become available. Is this
still true?
Thanks a lot,
Trev
--
389 users mailing list
389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>https://admin.fedoraproject.org/mailman/listinfo/389-users
--
389 users mailing list
389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>https://admin.fedoraproject.org/mailman/listinfo/389-users
--
389 users mailing list
389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>https://admin.fedoraproject.org/mailman/listinfo/389-users
--
389 users mailing list
389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>https://admin.fedoraproject.org/mailman/listinfo/389-users
--
389 users mailing list
389-users@lists.fedoraproject.org<mailto:389-users@lists.fedoraproject.org>https://admin.fedoraproject.org/mailman/listinfo/389-users