Unindexed LDAP searches

[pki-bot]

This issue was migrated from Pagure Issue #2603. Originally filed by cheimes (@tiran) on 2017-03-02 13:39:07:

• Assigned to cheimes (@tiran)

---

Here is another ticket related to performance.

Today Nathan suggested that I use logconv.pl to analyze 389-DS's logs for unindexed queries. I found a bunch of queries that could benefit from an index. The majority of missing indexes seem to be related to Dogtag PKI. Some of them are FreeIPA. I have already created https://pagure.io/freeipa/issue/6722 for FreeIPA.

I see a bunch of bind related missing indexes. It looks like RA cert authentication could benefit from an index a lot: Unindexed Filter: (description=2;7;cn=certificate authority,o=ipa.example;cn=ipa ra,o=ipa.example) (occurrances 133).

Please consider missing indexes for Dogtag 10.3 and Fedora 25. I would like to improve performance of FreeIPA 4.5.

# logconv.pl -U /var/log/dirsrv/slapd-IPA-EXAMPLE/access*   
Access Log Analyzer 8.2
Command: logconv.pl /var/log/dirsrv/slapd-IPA-EXAMPLE/access /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170224-165443 /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170225-165520 /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170226-165524 /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170227-165529 /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170228-170026 /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170301-170120 /var/log/dirsrv/slapd-IPA-EXAMPLE/access.rotationinfo
Processing 7 Access Log(s)...

[007] /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170224-165443  size (bytes):      7348817
     25000 Lines Processed          4601976 of      7348817 bytes (62.622%)

[006] /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170225-165520  size (bytes):      4963213
     25000 Lines Processed          4650135 of      4963213 bytes (93.692%)

[005] /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170226-165524  size (bytes):      3669580

[004] /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170227-165529  size (bytes):      4170095

[003] /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170228-170026  size (bytes):      5539548

[002] /var/log/dirsrv/slapd-IPA-EXAMPLE/access.20170301-170120  size (bytes):      2769122

[001] /var/log/dirsrv/slapd-IPA-EXAMPLE/access  size (bytes):      1554424

Total Log Lines Analysed:  142232

----------- Access Log Output ------------

Start of Logs:    24/Feb/2017:16:54:45.321852489
End of Logs:      02/Mar/2017:18:14:40.260858057

Processed Log Time:  8 Days, 1 Hours, 19 Minutes, 54.938998784 Seconds

Restarts:                     18
 Secure Protocol Versions:
  - TLS1.2 client bound as uid=pkidbuser,ou=people,o=ipaca - 107
  - TLS1.2 128-bit AES; client CN=CA Subsystem,O=IPA.EXAMPLE; issuer CN=Certificate Authority,O=IPA.EXAMPLE - 107
  - TLS1.2 128-bit AES-GCM - 41
  - TLS1.2 128-bit AES - 74

Peak Concurrent Connections:  178
Total Operations:             67324
Total Results:                65446
Overall Performance:          97.2%

Total Connections:            2715          (0.00/sec)  (0.23/min)
 - LDAP Connections:          2183          (0.00/sec)  (0.19/min)
 - LDAPI Connections:         321           (0.00/sec)  (0.03/min)
 - LDAPS Connections:         211           (0.00/sec)  (0.02/min)
 - StartTLS Extended Ops:     14            (0.00/sec)  (0.00/min)

Searches:                     48715         (0.07/sec)  (4.20/min)
Modifications:                2791          (0.00/sec)  (0.24/min)
Adds:                         6017          (0.01/sec)  (0.52/min)
Deletes:                      42            (0.00/sec)  (0.00/min)
Mod RDNs:                     9             (0.00/sec)  (0.00/min)
Compares:                     0             (0.00/sec)  (0.00/min)
Binds:                        5963          (0.01/sec)  (0.51/min)

Proxied Auth Operations:      0
Persistent Searches:          48
Internal Operations:          0
Entry Operations:             0
Extended Operations:          2245
Abandoned Requests:           0
Smart Referrals Received:     0

VLV Operations:               1542
VLV Unindexed Searches:       0
VLV Unindexed Components:     1030
SORT Operations:              534

Entire Search Base Queries:   36
Paged Searches:               3537
Unindexed Searches:           0
Unindexed Components:         292

  Unindexed Component Summary - 292 total unindexed components
  -  Unindexed Filters:   Filter:   (description=2;7;cn=certificate authority,o=ipa.example;cn=ipa ra,o=ipa.example) (occurrences 133)
                          - Bind DN:  cn=directory manager (binds  133)

  -  Unindexed Filters:   Filter:   (&(objectclass=ipaconfigobject)(ipaconfigstring=enabledservice)(cn=kra)) (occurrences 58)
                          - Bind DN:   (binds  58)

  -  Unindexed Filters:   Filter:   (&(ipakeyusage=digitalsignature)(memberprincipal=host/replica1.ipa.example@ipa.example)) (occurrences 20)
                          - Bind DN:  cn=directory manager (binds  20)

  -  Unindexed Filters:   Filter:   (&(ipakeyusage=dataencipherment)(memberprincipal=host/replica1.ipa.example@ipa.example)) (occurrences 20)
                          - Bind DN:  cn=directory manager (binds  20)

  -  Unindexed Filters:   Filter:   (&(objectclass=ipaconfigobject)(ipaconfigstring=enabledservice)(cn=ca)) (occurrences 14)
                          - Bind DN:   (binds  14)

  -  Unindexed Filters:   Filter:   (objectclass=*) (occurrences 10)
                          - Bind DN:  cn=directory manager (binds  10)

  -  Unindexed Filters:   Filter:   (cacertificate;binary=*) (occurrences 8)
                          - Bind DN:   (binds  8)

  -  Unindexed Filters:   Filter:   (ipaconfigstring=enabledservice) (occurrences 5)
                          - Bind DN:  cn=directory manager (binds  5)

  -  Unindexed Filters:   Filter:   (&(automountkey=*)(objectclass=automount)) (occurrences 4)
                          - Bind DN:   (binds  4)

  -  Unindexed Filters:   Filter:   (&(requeststate=approved)(requestid=*)) (occurrences 3)
                          - Bind DN:  cn=directory manager (binds  3)

  -  Unindexed Filters:   Filter:   (dnahostname=master.ipa.example) (occurrences 2)
                          - Bind DN:  cn=directory manager (binds  2)

  -  Unindexed Filters:   Filter:   (&(automountmapname=auto.direct)(objectclass=automountmap)) (occurrences 2)
                          - Bind DN:   (binds  2)

  -  Unindexed Filters:   Filter:   (&(automountmapname=auto.master)(objectclass=automountmap)) (occurrences 2)
                          - Bind DN:   (binds  2)

  -  Unindexed Filters:   Filter:   (description=2;6;cn=certificate authority,o=ipa.example;cn=ipa-ca-agent,o=ipa.example) (occurrences 2)
                          - Bind DN:  cn=directory manager (binds  2)

  -  Unindexed Filters:   Filter:   (&(|(sshfprecord=*replica1*)(hiprecord=*replica1*)(spfrecord=*replica1*)(kxrecord=*replica1*)(nxtrecord=*replica1*)(mxrecord=*replica1*)(aaaarecord=*replica1*)(mdrecord=*replica1*)(arecord=*replica1*)(dlvrecord=*replica1*)(tlsarecord=*replica1*)(ptrrecord=*replica1*)(sigrecord=*replica1*)(idnsname=*replica1*)(afsdbrecord=*replica1*)(aplrecord=*replica1*)(urirecord=*replica1*)(naptrrecord=*replica1*)(nsrecord=*replica1*)(locrecord=*replica1*)(dnamerecord=*replica1*)(rprecord=*replica1*)(dhcidrecord=*replica1*)(ipseckeyrecord=*replica1*)(rrsigrecord=*replica1*)(hinforecord=*replica1*)(cnamerecord=*replica1*)(certrecord=*replica1*)(srvrecord=*replica1*)(dsrecord=*replica1*)(txtrecord=*replica1*)(nsecrecord=*replica1*)(a6record=*replica1*)(keyrecord=*replica1*)(minforecord=*replica1*))(&(objectclass=top)(objectclass=idnsrecord))) (occurrences 2)
                          - Bind DN:  cn=directory manager (binds  2)

  -  Unindexed Filters:   Filter:   (nsrecord=replica1.ipa.example.) (occurrences 1)
                          - Bind DN:  cn=directory manager (binds  1)

  -  Unindexed Filters:   Filter:   (memberprincipal=*/replica1.ipa.example@ipa.example) (occurrences 1)
                          - Bind DN:  cn=directory manager (binds  1)

  -  Unindexed Filters:   Filter:   (|(ipaconfigstring=ipaca)(ipaconfigstring=compatca)) (occurrences 1)
                          - Bind DN:  cn=directory manager (binds  1)

  -  Unindexed Filters:   Filter:   (dnahostname=replica1.ipa.example) (occurrences 1)
                          - Bind DN:  cn=directory manager (binds  1)

  -  Unindexed Filters:   Filter:   (ipacertsubject=cn=certificate authority,o=ipa.example) (occurrences 1)
                          - Bind DN:  cn=directory manager (binds  1)

  -  Unindexed Filters:   Filter:   (&(ipserviceport=659)(ipserviceprotocol=udp)(objectclass=ipservice)) (occurrences 1)
                          - Bind DN:   (binds  1)

  -  Unindexed Filters:   Filter:   (&(ipserviceport=936)(ipserviceprotocol=udp)(objectclass=ipservice)) (occurrences 1)
                          - Bind DN:   (binds  1)

  -  Unindexed Bind DNs:  Bind DN:  cn=directory manager (binds 202)
                          - Unindexed Filter: (ipacertsubject=cn=certificate authority,o=ipa.example) (occurrances 1)
                          - Unindexed Filter: (|(ipaconfigstring=ipaca)(ipaconfigstring=compatca)) (occurrances 1)
                          - Unindexed Filter: (memberprincipal=*/replica1.ipa.example@ipa.example) (occurrances 1)
                          - Unindexed Filter: (dnahostname=replica1.ipa.example) (occurrances 1)
                          - Unindexed Filter: (nsrecord=replica1.ipa.example.) (occurrances 1)
                          - Unindexed Filter: (dnahostname=master.ipa.example) (occurrances 2)
                          - Unindexed Filter: (&(|(sshfprecord=*replica1*)(hiprecord=*replica1*)(spfrecord=*replica1*)(kxrecord=*replica1*)(nxtrecord=*replica1*)(mxrecord=*replica1*)(aaaarecord=*replica1*)(mdrecord=*replica1*)(arecord=*replica1*)(dlvrecord=*replica1*)(tlsarecord=*replica1*)(ptrrecord=*replica1*)(sigrecord=*replica1*)(idnsname=*replica1*)(afsdbrecord=*replica1*)(aplrecord=*replica1*)(urirecord=*replica1*)(naptrrecord=*replica1*)(nsrecord=*replica1*)(locrecord=*replica1*)(dnamerecord=*replica1*)(rprecord=*replica1*)(dhcidrecord=*replica1*)(ipseckeyrecord=*replica1*)(rrsigrecord=*replica1*)(hinforecord=*replica1*)(cnamerecord=*replica1*)(certrecord=*replica1*)(srvrecord=*replica1*)(dsrecord=*replica1*)(txtrecord=*replica1*)(nsecrecord=*replica1*)(a6record=*replica1*)(keyrecord=*replica1*)(minforecord=*replica1*))(&(objectclass=top)(objectclass=idnsrecord))) (occurrances 2)
                          - Unindexed Filter: (description=2;6;cn=certificate authority,o=ipa.example;cn=ipa-ca-agent,o=ipa.example) (occurrances 2)
                          - Unindexed Filter: (&(requeststate=approved)(requestid=*)) (occurrances 3)
                          - Unindexed Filter: (ipaconfigstring=enabledservice) (occurrances 5)
                          - Unindexed Filter: (objectclass=*) (occurrances 10)
                          - Unindexed Filter: (&(ipakeyusage=dataencipherment)(memberprincipal=host/replica1.ipa.example@ipa.example)) (occurrances 20)
                          - Unindexed Filter: (&(ipakeyusage=digitalsignature)(memberprincipal=host/replica1.ipa.example@ipa.example)) (occurrances 20)
                          - Unindexed Filter: (description=2;7;cn=certificate authority,o=ipa.example;cn=ipa ra,o=ipa.example) (occurrances 133)

  -  Unindexed Bind DNs:  Bind DN:   (binds 90)
                          - Unindexed Filter: (&(ipserviceport=659)(ipserviceprotocol=udp)(objectclass=ipservice)) (occurrances 1)
                          - Unindexed Filter: (&(ipserviceport=936)(ipserviceprotocol=udp)(objectclass=ipservice)) (occurrances 1)
                          - Unindexed Filter: (&(automountmapname=auto.direct)(objectclass=automountmap)) (occurrances 2)
                          - Unindexed Filter: (&(automountmapname=auto.master)(objectclass=automountmap)) (occurrances 2)
                          - Unindexed Filter: (&(automountkey=*)(objectclass=automount)) (occurrances 4)
                          - Unindexed Filter: (cacertificate;binary=*) (occurrances 8)
                          - Unindexed Filter: (&(objectclass=ipaconfigobject)(ipaconfigstring=enabledservice)(cn=ca)) (occurrances 14)
                          - Unindexed Filter: (&(objectclass=ipaconfigobject)(ipaconfigstring=enabledservice)(cn=kra)) (occurrances 58)

FDs Taken:                    3036
FDs Returned:                 2861
Highest FD Taken:             162

Broken Pipes:                 0
Connections Reset By Peer:    0
Resource Unavailable:         0
Max BER Size Exceeded:        0

Binds:                        5963
Unbinds:                      2689
 - LDAP v2 Binds:             45
 - LDAP v3 Binds:             5644
 - AUTOBINDs:                 274
 - SSL Client Binds:          0
 - Failed SSL Client Binds:   0
 - SASL Binds:                5575
    GSSAPI - 5194
    EXTERNAL - 381
 - Directory Manager Binds:   3
 - Anonymous Binds:           5306
 - Other Binds:               654

[pki-bot]

Comment from mharmsen (@mharmsen) at 2017-04-13 13:01:24

Metadata Update from @mharmsen:

• Custom field component adjusted to General
• Custom field feature adjusted to ''
• Custom field origin adjusted to Community
• Custom field proposedmilestone adjusted to ''
• Custom field proposedpriority adjusted to ''
• Custom field reviewer adjusted to ''
• Custom field type adjusted to defect
• Custom field version adjusted to ''
• Issue priority set to: ---
• Issue set to the milestone: 0.0 NEEDS_TRIAGE

[pki-bot]

Comment from mharmsen (@mharmsen) at 2017-04-20 18:43:06

Per PKI Bug Council of April 20, 2017: 10.3.11 - major

This bug would need to be fixed in the master before it is back-ported to 10.3.x.

[pki-bot]

Comment from mharmsen (@mharmsen) at 2017-04-20 18:43:07

Metadata Update from @mharmsen:

• Issue priority set to: major (was: ---)
• Issue set to the milestone: 10.3.11 (was: 0.0 NEEDS_TRIAGE)

[pki-bot]

Comment from edewata (@edewata) at 2017-11-01 21:45:35

Metadata Update from @edewata:

• Issue set to the milestone: 0.0 NEEDS_TRIAGE (was: 10.3.11)

[pki-bot]

Comment from mharmsen (@mharmsen) at 2017-11-09 19:06:07

Metadata Update from @mharmsen:

• Issue assigned to tiran

[pki-bot]

Comment from mharmsen (@mharmsen) at 2017-11-14 11:35:40

Per meeting of 20171113 - 10.6

[pki-bot]

Comment from mharmsen (@mharmsen) at 2017-11-14 11:35:40

Metadata Update from @mharmsen:

• Issue set to the milestone: 10.6 (was: 0.0 NEEDS_TRIAGE)

[pki-bot]

Comment from mharmsen (@mharmsen) at 2018-02-21 16:56:00

[20180221] Per tiran on IRC: FUTURE

[pki-bot]

Comment from mharmsen (@mharmsen) at 2018-02-21 16:56:01

Metadata Update from @mharmsen:

• Issue set to the milestone: FUTURE (was: 10.6)