[Freeipa-users] IPA Load Problems?
Rich Megginson
rmeggins at redhat.com
Fri Aug 30 20:48:35 UTC 2013
On 08/30/2013 02:34 PM, John Moyer wrote:
> I put the output in a log and did some command line magic. It doesn't
> look bad at all. Highest Etime was 6.
>
> cat access_output | grep Etime | sort -n | uniq -c
> 225 - Etime: 0
> 67 - Etime: 1
> 1 - Etime: 11
> 138 - Etime: 2
> 74 - Etime: 3
> 35 - Etime: 4
> 7 - Etime: 5
> 4 - Etime: 6
>
Then I don't understand what exactly is taking 900 seconds?
>
>
> Thanks,
> _____________________________________________________
> John Moyer
> Director, IT Operations
> *Digital Reasoning Systems, Inc.*
> John.Moyer at digitalreasoning.com <mailto:john.moyer at digitalreasoning.com>
> Office:703.678.2311
> Mobile:240.460.0023
> Fax:703.678.2312
> www.digitalreasoning.com <http://www.digitalreasoning.com/>
>
> On Aug 30, 2013, at 4:25 PM, Rich Megginson <rmeggins at redhat.com
> <mailto:rmeggins at redhat.com>> wrote:
>
>> On 08/30/2013 02:10 PM, John Moyer wrote:
>>> So I'm trying to focus on just one use case having the performance
>>> issues. I figured out my JIRA server does a sync against this which
>>> brings it to it's knees. It takes it 900 seconds to complete the
>>> sync and seems to go through every group and user on the machine. I
>>> have the base for the user group set to
>>> cn=users,cn=accounts,dc=example,dc=com and the groups to
>>> cn=groups,cn=accounts,dc=example,dc=com. This sync took around 60
>>> seconds off my openldap server I had before this. Any suggestions
>>> what to look at?
>>
>> The access log should have an operation which has etime=900 (or at
>> least a very high etime)
>>
>> If you do logconv.pl -V it will print out a lot of information,
>> including the highest etimes. You can then use this report to look
>> at the access logs to find out exactly which operations had these
>> high etimes.
>>
>>>
>>>
>>> Thanks,
>>> _____________________________________________________
>>> John Moyer
>>> Director, IT Operations
>>> *Digital Reasoning Systems, Inc.*
>>> John.Moyer at digitalreasoning.com <mailto:john.moyer at digitalreasoning.com>
>>> Office:703.678.2311
>>> Mobile:240.460.0023
>>> Fax:703.678.2312
>>> www.digitalreasoning.com <http://www.digitalreasoning.com/>
>>>
>>> On Aug 30, 2013, at 3:49 PM, John Moyer
>>> <john.moyer at digitalreasoning.com
>>> <mailto:john.moyer at digitalreasoning.com>> wrote:
>>>
>>>> I'm sorry that was my top unique filter list not my unindexed list.
>>>> Please disregard my last email.
>>>>
>>>>
>>>> Thanks,
>>>> _____________________________________________________
>>>> John Moyer
>>>> Director, IT Operations
>>>> *Digital Reasoning Systems, Inc.*
>>>> John.Moyer at digitalreasoning.com
>>>> <mailto:john.moyer at digitalreasoning.com>
>>>> Office:703.678.2311
>>>> Mobile:240.460.0023
>>>> Fax:703.678.2312
>>>> www.digitalreasoning.com <http://www.digitalreasoning.com/>
>>>>
>>>> On Aug 30, 2013, at 3:47 PM, John Moyer
>>>> <john.moyer at digitalreasoning.com
>>>> <mailto:john.moyer at digitalreasoning.com>> wrote:
>>>>
>>>>> If objectclass eq is already indexed how are these on my top
>>>>> unindexed list? Wouldn't objectclass eq cover this
>>>>> (objectclass=inetorgperson)? and the third and fourth entry? I
>>>>> apologize if I'm way off as I am new to the intricacies of LDAP
>>>>> indexing.
>>>>>
>>>>>
>>>>>
>>>>> Thanks,
>>>>> _____________________________________________________
>>>>> John Moyer
>>>>> Director, IT Operations
>>>>>
>>>>> On Aug 30, 2013, at 3:41 PM, Rich Megginson <rmeggins at redhat.com
>>>>> <mailto:rmeggins at redhat.com>> wrote:
>>>>>
>>>>>> On 08/30/2013 01:31 PM, John Moyer wrote:
>>>>>>> Rob or anyone else,
>>>>>>>
>>>>>>> So while struggling along on this server I just grabbed the logs
>>>>>>> off it and ran that log program with the options you suggested.
>>>>>>> There are a lot of unindexed requests. These are the top
>>>>>>> issues I've removed the one username that showed up.
>>>>>>>
>>>>>>> So just to double check what I'm thinking. I need to create
>>>>>>> three indexes
>>>>>>> 1. objectclass pres
>>>>>> No, do not create this one
>>>>>>> 2. objectclass eq
>>>>>> This should already be indexed
>>>>>>> 3. uid pres
>>>>>> I suppose the UI might be doing this search?
>>>>>>>
>>>>>>> Please let me know if I'm reading this correctly or if I'm way off?
>>>>>>>
>>>>>>>
>>>>>>> 7337 (objectclass=inetorgperson)
>>>>>>> 4597 (objectclass=*)
>>>>>>> 4560 (&(objectclass=inetorgperson)(uid=senior.developer.login))
>>>>>>> 307 (objectclass=krbticketpolicyaux)
>>>>>>> 292 (uid=*)
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Thanks,
>>>>>>> _____________________________________________________
>>>>>>> John Moyer
>>>>>>> Director, IT Operations
>>>>>>> *Digital Reasoning Systems, Inc.*
>>>>>>> John.Moyer at digitalreasoning.com
>>>>>>> <mailto:john.moyer at digitalreasoning.com>
>>>>>>> Office:703.678.2311
>>>>>>> Mobile:240.460.0023
>>>>>>> Fax:703.678.2312
>>>>>>> www.digitalreasoning.com <http://www.digitalreasoning.com/>
>>>>>>>
>>>>>>> On Aug 28, 2013, at 11:40 AM, Rob Crittenden
>>>>>>> <rcritten at redhat.com <mailto:rcritten at redhat.com>> wrote:
>>>>>>>
>>>>>>>> John Moyer wrote:
>>>>>>>>> So this method of search logs is great, and it shows some
>>>>>>>>> indexes that would likely highly increase efficiency with my
>>>>>>>>> usage. So, are there instructions how to do that? or do you
>>>>>>>>> know off hand how to do that?
>>>>>>>>
>>>>>>>> I'd start with
>>>>>>>> https://access.redhat.com/site/documentation/en-US/Red_Hat_Directory_Server/9.0/html-single/Administration_Guide/index.html#Managing_Indexes-About_Indexes
>>>>>>>>
>>>>>>>> Note that you'll want to create the same index on all hosts.
>>>>>>>> This configuration is not replicated.
>>>>>>>>
>>>>>>>> You can see the ones we create in /usr/share/ipa/indices.ldif
>>>>>>>> and /usr/share/ipa/updates/20-indices.update
>>>>>>>>
>>>>>>>> rob
>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Thanks,
>>>>>>>>> _____________________________________________________
>>>>>>>>> John Moyer
>>>>>>>>> Director, IT Operations
>>>>>>>>> Digital Reasoning Systems, Inc.
>>>>>>>>> John.Moyer at digitalreasoning.com
>>>>>>>>> <mailto:John.Moyer at digitalreasoning.com>
>>>>>>>>> Office:703.678.2311
>>>>>>>>> Mobile:240.460.0023
>>>>>>>>> Fax:703.678.2312
>>>>>>>>> www.digitalreasoning.com
>>>>>>>>>
>>>>>>>>> On Aug 27, 2013, at 4:45 PM, Rob Crittenden
>>>>>>>>> <rcritten at redhat.com> wrote:
>>>>>>>>>
>>>>>>>>>> John Moyer wrote:
>>>>>>>>>>> Wow, this is quite insightful, this is the output from that,
>>>>>>>>>>> it looks like there aren't many unindexed searches (319
>>>>>>>>>>> doesn't seem like a lot to me at least). Do you have any
>>>>>>>>>>> suggestions from this output?
>>>>>>>>>>
>>>>>>>>>> There are a slew of options you can provide to logconv.pl. I
>>>>>>>>>> typically use logconv.pl -ula
>>>>>>>>>> /var/log/dirsrv/slapd-EXAMPLE-COM/access when doing search
>>>>>>>>>> analysis.
>>>>>>>>>>
>>>>>>>>>> rob
>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> Start of Log: 27/Aug/2013:02:36:08
>>>>>>>>>>> End of Log: 27/Aug/2013:12:17:15
>>>>>>>>>>>
>>>>>>>>>>> Processed Log Time: 9 Hours, 41 Minutes, 7 Seconds
>>>>>>>>>>>
>>>>>>>>>>> Restarts: 2
>>>>>>>>>>> Total Connections: 45224
>>>>>>>>>>> SSL Connections: 44735
>>>>>>>>>>> Peak Concurrent Connections: 76
>>>>>>>>>>> Total Operations: 132568
>>>>>>>>>>> Total Results: 132737
>>>>>>>>>>> Overall Performance: 100.0%
>>>>>>>>>>>
>>>>>>>>>>> Searches: 61318 (1.76/sec)
>>>>>>>>>>> (105.52/min)
>>>>>>>>>>> Modifications: 277 (0.01/sec) (0.48/min)
>>>>>>>>>>> Adds: 10 (0.00/sec) (0.02/min)
>>>>>>>>>>> Deletes: 12 (0.00/sec) (0.02/min)
>>>>>>>>>>> Mod RDNs: 0 (0.00/sec) (0.00/min)
>>>>>>>>>>> Compares: 0 (0.00/sec) (0.00/min)
>>>>>>>>>>> Binds: 62143 (1.78/sec)
>>>>>>>>>>> (106.94/min)
>>>>>>>>>>>
>>>>>>>>>>> Proxied Auth Operations: 0
>>>>>>>>>>> Persistent Searches: 3
>>>>>>>>>>> Internal Operations: 0
>>>>>>>>>>> Entry Operations: 0
>>>>>>>>>>> Extended Operations: 8808
>>>>>>>>>>> Abandoned Requests: 0
>>>>>>>>>>> Smart Referrals Received: 0
>>>>>>>>>>>
>>>>>>>>>>> VLV Operations: 0
>>>>>>>>>>> VLV Unindexed Searches: 0
>>>>>>>>>>> SORT Operations: 353
>>>>>>>>>>>
>>>>>>>>>>> Entire Search Base Queries: 106
>>>>>>>>>>> Unindexed Searches: 319
>>>>>>>>>>>
>>>>>>>>>>> FDs Taken: 45262
>>>>>>>>>>> FDs Returned: 45210
>>>>>>>>>>> Highest FD Taken: 139
>>>>>>>>>>>
>>>>>>>>>>> Broken Pipes: 0
>>>>>>>>>>> Connections Reset By Peer: 0
>>>>>>>>>>> Resource Unavailable: 0
>>>>>>>>>>>
>>>>>>>>>>> Binds: 62143
>>>>>>>>>>> Unbinds: 44539
>>>>>>>>>>>
>>>>>>>>>>> LDAP v2 Binds: 2
>>>>>>>>>>> LDAP v3 Binds: 62141
>>>>>>>>>>> SSL Client Binds: 0
>>>>>>>>>>> Failed SSL Client Binds: 0
>>>>>>>>>>> SASL Binds: 1466
>>>>>>>>>>> 1458 GSSAPI
>>>>>>>>>>> 8 EXTERNAL
>>>>>>>>>>>
>>>>>>>>>>> Directory Manager Binds: 10
>>>>>>>>>>> Anonymous Binds: 1476
>>>>>>>>>>> Other Binds: 60657
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> Thanks,
>>>>>>>>>>> _____________________________________________________
>>>>>>>>>>> John Moyer
>>>>>>>>>>> Director, IT Operations
>>>>>>>>>>> On Aug 27, 2013, at 1:13 PM, Rob Crittenden
>>>>>>>>>>> <rcritten at redhat.com> wrote:
>>>>>>>>>>>
>>>>>>>>>>>> John Moyer wrote:
>>>>>>>>>>>>> Is there any way to see what fields are index'ed?
>>>>>>>>>>>>
>>>>>>>>>>>> $ ldapsearch -LLL -D 'cn=directory manager' -W -x -b
>>>>>>>>>>>> 'cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config'
>>>>>>>>>>>>
>>>>>>>>>>>> Your best bet is to use the logconv.pl tool to examine your
>>>>>>>>>>>> logs.
>>>>>>>>>>>>
>>>>>>>>>>>> rob
>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> Thanks,
>>>>>>>>>>>>> _____________________________________________________
>>>>>>>>>>>>> John Moyer
>>>>>>>>>>>>> Director, IT Operations
>>>>>>>>>>>>> Digital Reasoning Systems, Inc.
>>>>>>>>>>>>> John.Moyer at digitalreasoning.com
>>>>>>>>>>>>> Office:703.678.2311
>>>>>>>>>>>>> Mobile:240.460.0023
>>>>>>>>>>>>> Fax:703.678.2312
>>>>>>>>>>>>> www.digitalreasoning.com
>>>>>>>>>>>>>
>>>>>>>>>>>>> On Aug 27, 2013, at 10:36 AM, John Moyer
>>>>>>>>>>>>> <john.moyer at digitalreasoning.com> wrote:
>>>>>>>>>>>>>
>>>>>>>>>>>>>> That looks like the output I just got shown below:
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> dn: cn=mapping tree,cn=config
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> dn: cn=dc\3Dexample\2Cdc\3Dcom,cn=mapping tree,cn=config
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> dn: cn=replica,cn=dc\3Dexample\2Cdc\3Dcom,cn=mapping
>>>>>>>>>>>>>> tree,cn=config
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> dn: cn=meToipa2.example.com
>>>>>>>>>>>>>> <http://metoipa2.example.com/>,cn=replica,cn=dc\3Dexample\
>>>>>>>>>>>>>> 2Cdc\3Dcom,cn=mapping tree,cn=config
>>>>>>>>>>>>>> nsDS5ReplicatedAttributeList: (objectclass=*) $ EXCLUDE
>>>>>>>>>>>>>> memberof idnssoaserial
>>>>>>>>>>>>>> entryusn krblastsuccessfulauth krblastfailedauth
>>>>>>>>>>>>>> krbloginfailedcount
>>>>>>>>>>>>>> nsDS5ReplicatedAttributeListTotal: (objectclass=*) $
>>>>>>>>>>>>>> EXCLUDE entryusn krblasts
>>>>>>>>>>>>>> uccessfulauth krblastfailedauth krbloginfailedcount
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Thanks,
>>>>>>>>>>>>>> _____________________________________________________
>>>>>>>>>>>>>> John Moyer
>>>>>>>>>>>>>> Director, IT Operations
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> On Aug 27, 2013, at 10:14 AM, Rob Crittenden
>>>>>>>>>>>>>> <rcritten at redhat.com> wrote:
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> John Moyer wrote:
>>>>>>>>>>>>>>>> Ok, so we tried to implement this again, and as soon as
>>>>>>>>>>>>>>>> we put on a
>>>>>>>>>>>>>>>> server that authenticates heavily the IPA came to it's
>>>>>>>>>>>>>>>> knees again.
>>>>>>>>>>>>>>>> This time I was able to watch it closely and try to
>>>>>>>>>>>>>>>> troubleshoot a lot
>>>>>>>>>>>>>>>> more, and also know exactly what server caused it
>>>>>>>>>>>>>>>> (Mercurial with help
>>>>>>>>>>>>>>>> of bamboo). This runs fine on a normal old openldap
>>>>>>>>>>>>>>>> servers. The
>>>>>>>>>>>>>>>> user is logging in very quickly and each time it logs
>>>>>>>>>>>>>>>> in I can see in
>>>>>>>>>>>>>>>> the logs that the krbLastsuccessfullogin parameter (or
>>>>>>>>>>>>>>>> whatever it is
>>>>>>>>>>>>>>>> called) is updated over and over and over in the changelog
>>>>>>>>>>>>>>>> (/var/lib/dirsrv/slapd-$instanceid/db) those logs are
>>>>>>>>>>>>>>>> filling VERY
>>>>>>>>>>>>>>>> quickly and then disappear fairly quickly as well.
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Issue 1: This is causing severe disk latency which
>>>>>>>>>>>>>>>> obviously slows
>>>>>>>>>>>>>>>> everything down wait times were around 25%+
>>>>>>>>>>>>>>>> Issue 2: These changes need to be replicated to my
>>>>>>>>>>>>>>>> slave server thus
>>>>>>>>>>>>>>>> adding to the mess
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> My question is, why does the IPA server fail to keep up
>>>>>>>>>>>>>>>> with the load
>>>>>>>>>>>>>>>> when the openLDAP server didn't have an issue. Indexes?
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> I'm running the following:
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> CentOS release 6.4 (Final)
>>>>>>>>>>>>>>>> 389-ds-base-1.2.11.15-20.el6_4.x86_64
>>>>>>>>>>>>>>>> 389-ds-base-libs-1.2.11.15-20.el6_4.x86_64
>>>>>>>>>>>>>>>> ipa-python-3.0.0-26.el6_4.4.x86_64
>>>>>>>>>>>>>>>> ipa-admintools-3.0.0-26.el6_4.4.x86_64
>>>>>>>>>>>>>>>> ipa-pki-common-theme-9.0.3-7.el6.noarch
>>>>>>>>>>>>>>>> python-iniparse-0.3.1-2.1.el6.noarch
>>>>>>>>>>>>>>>> ipa-server-3.0.0-26.el6_4.4.x86_64
>>>>>>>>>>>>>>>> ipa-pki-ca-theme-9.0.3-7.el6.noarch
>>>>>>>>>>>>>>>> ipa-server-selinux-3.0.0-26.el6_4.4.x86_64
>>>>>>>>>>>>>>>> libipa_hbac-1.9.2-82.7.el6_4.x86_64
>>>>>>>>>>>>>>>> ipa-client-3.0.0-26.el6_4.4.x86_64
>>>>>>>>>>>>>>>> libipa_hbac-python-1.9.2-82.7.el6_4.x86_64
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> So I've implemented this server anyway (against my
>>>>>>>>>>>>>>>> better judgement with
>>>>>>>>>>>>>>>> these issues and just made the user that logs into
>>>>>>>>>>>>>>>> mercurial a local
>>>>>>>>>>>>>>>> user instead of IPA).
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Also note before I did that for fun I implemented a RAM
>>>>>>>>>>>>>>>> disk to put the
>>>>>>>>>>>>>>>> change logs on, and that dropped the wait time to 0
>>>>>>>>>>>>>>>> (except bursts where
>>>>>>>>>>>>>>>> it would raise to 30 to write the access log) but the
>>>>>>>>>>>>>>>> CPU drove to 100%
>>>>>>>>>>>>>>>> trying to keep up with the load. I have also killed
>>>>>>>>>>>>>>>> the replication as
>>>>>>>>>>>>>>>> well.
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Any help would be appreciated.
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> krblastsuccessfulauth should be excluded from
>>>>>>>>>>>>>>> replication, though I guess that doesn't prevent it from
>>>>>>>>>>>>>>> ending up in the changelog.
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> You can confirm that they are excluded by searching the
>>>>>>>>>>>>>>> agreements:
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> $ ldapsearch -LLL -x -b 'cn=mapping tree,cn=config' -D
>>>>>>>>>>>>>>> 'cn=directory manager' -W nsDS5ReplicatedAttributeList
>>>>>>>>>>>>>>> nsDS5ReplicatedAttributeListTotal
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> They should look like:
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> nsDS5ReplicatedAttributeList: (objectclass=*) $ EXCLUDE
>>>>>>>>>>>>>>> memberof idnssoaserial entryusn krblastsuccessfulauth
>>>>>>>>>>>>>>> krblastfailedauth krbloginfailedcount
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> nsDS5ReplicatedAttributeListTotal: (objectclass=*) $
>>>>>>>>>>>>>>> EXCLUDE entryusn krblastsuccessfulauth krblastfailedauth
>>>>>>>>>>>>>>> krbloginfailedcount
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> rob
>>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20130830/93e75913/attachment.htm>
More information about the Freeipa-users
mailing list