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(a)localhost.service changed on disk,
'systemctl daemon-reload' recommended.
Warning: Unit file of dirsrv(a)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(a)redhat.com
<mailto:mareynol@redhat.com>>
>> Reply-To: "mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>"
>> <mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>>
>> Date: Tuesday, December 9, 2014 at 3:21 PM
>> To: Trevor Fong <trevor.fong(a)ubc.ca <mailto:trevor.fong@ubc.ca>>,
>> "mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>"
>> <mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>>,
>> "389-users(a)lists.fedoraproject.org
>> <mailto:389-users@lists.fedoraproject.org>"
>> <389-users(a)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(a)redhat.com
<mailto:mareynol@redhat.com>>
>>> Reply-To: "mreynolds(a)redhat.com
<mailto:mreynolds@redhat.com>"
>>> <mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>>
>>> Date: Tuesday, December 9, 2014 at 9:33 AM
>>> To: Trevor Fong <trevor.fong(a)ubc.ca <mailto:trevor.fong@ubc.ca>>,
>>> "mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>"
>>> <mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>>,
>>> "389-users(a)lists.fedoraproject.org
>>> <mailto:389-users@lists.fedoraproject.org>"
>>> <389-users(a)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(a)redhat.com
<mailto:mareynol@redhat.com>>
>>>> Reply-To: "mreynolds(a)redhat.com
<mailto:mreynolds@redhat.com>"
>>>> <mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>>
>>>> Date: Tuesday, December 9, 2014 at 7:25 AM
>>>> To: "389-users(a)lists.fedoraproject.org
>>>> <mailto:389-users@lists.fedoraproject.org>"
>>>> <389-users(a)lists.fedoraproject.org
>>>> <mailto:389-users@lists.fedoraproject.org>>, Trevor Fong
>>>> <trevor.fong(a)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(a)redhat.com
>>>>> <mailto:mareynol@redhat.com>>
>>>>> Reply-To: "mreynolds(a)redhat.com
<mailto:mreynolds@redhat.com>"
>>>>> <mreynolds(a)redhat.com <mailto:mreynolds@redhat.com>>
>>>>> Date: Monday, December 8, 2014 at 11:29 AM
>>>>> To: "389-users(a)lists.fedoraproject.org
>>>>> <mailto:389-users@lists.fedoraproject.org>"
>>>>> <389-users(a)lists.fedoraproject.org
>>>>> <mailto:389-users@lists.fedoraproject.org>>, Trevor Fong
>>>>> <trevor.fong(a)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.orghttps://admin.fedoraproject.org/mailman/listinfo/389-users
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> 389 users mailing list
>>>>>
389-users@lists.fedoraproject.orghttps://admin.fedoraproject.org/mailman/listinfo/389-users
>>>>
>>>
>>
>>
>>
>> --
>> 389 users mailing list
>> 389-users(a)lists.fedoraproject.org
>>
https://admin.fedoraproject.org/mailman/listinfo/389-users
>
>
>
> --
> 389 users mailing list
> 389-users(a)lists.fedoraproject.org
>
https://admin.fedoraproject.org/mailman/listinfo/389-users
--
389 users mailing list
389-users(a)lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users