[389-users] Re: ldapsearch performance problem

[Mark Reynolds]

On 06/15/2018 04:04 PM, Jan Kowalsky wrote:
>  Hi Marc,
>
>  thanks for answer, and the hint for indexes.
>
>  Am 15.06.2018 um 00:53 schrieb Mark Reynolds:
> > Can we see your access log showing the slow searches?  Are they
> > unindexed?  If you have unindexed searches they will bog down the entire
>  Whole log is difficult because of privacy, because it's a productive
>  environment with real user data.
>
>
>  What I can see are a log of unindexec component queries, most of them like:
>
>  [15/Jun/2018:21:51:14 +0200] conn=462 op=31251 SRCH
>  base="ou=Domains,dc=example,dc=org" scope=2
>
> filter="(&(objectClass=domainrelatedobject)(associatedDomain=example.net))"
>  attrs="associatedDomain inetDomainBaseDN"
>  [15/Jun/2018:21:51:14 +0200] conn=462 op=31251 RESULT err=0 tag=101
>  nentries=1 etime=0 notes=U
>
>  but I'm not shure, if they are really a problem, because there are only
>  about 60 entries in domainrelatedobject
>
>  more relevant could be that there is no index for alias:
>
>  [15/Jun/2018:21:50:21 +0200] conn=106426 op=1 SRCH
>  base="dc=example,dc=net" scope=2
>
> filter="(&(objectClass=kolabInetOrgPerson)(|(mail=[e-mail])(alias=[e-mail])(uid=test.user(a)example.net)))"
>  attrs="distinguishedName"
>  [15/Jun/2018:21:50:21 +0200] conn=106426 op=1 RESULT err=0 tag=101
>  nentries=1 etime=0 notes=U
>
>
> > server.  Do you see high cpu for ns-slapd?
>  no. not at all: avarage about 7 %, load avarage about 0.4 with max 0.6,
>  and no i/o wait.
>
>  The specific phenomena is: for a couple of seconds everything is smooth
>  but suddenly it hangs for about 1 until 4 or more seconds - and this
>  seems to be related to all queries in this moment.
>
> > Can you also run logconv.pl?
> >
> > logconv.pl -ulatn /var/log/dirsrv/slapd-YOUR_INSTANCE/access*
> >
> >
>  Access Log Analyzer 8.0
>  Command: logconv.pl /var/log/dirsrv/slapd-ldap0/access
>  Processing 1 Access Log(s)...
>
>  [001] /var/log/dirsrv/slapd-ldap0/access        size (bytes):      4715242
>        25000 Lines Processed          3430177 of      4715242 bytes (72.747%)
>
>
>  Total Log Lines Analysed:  33372
>
>
>  ----------- Access Log Output ------------
>
>  Start of Logs:    15/Jun/2018:19:06:52
>  End of Logs:      15/Jun/2018:19:26:39
>
>  Processed Log Time:  0 Hours, 19 Minutes, 47 Seconds
>
>  Restarts:                     0
>  Total Connections:            2225
>    - StartTLS Connections:      0
>    - LDAPS Connections:         0
>    - LDAPI Connections:         0
>  Peak Concurrent Connections:  11
>  Total Operations:             13362
>  Total Results:                13389
>  Overall Performance:          100.0%
>
>  Searches:                     10248         (8.63/sec)  (518.01/min)
>  Modifications:                0             (0.00/sec)  (0.00/min)
>  Adds:                         0             (0.00/sec)  (0.00/min)
>  Deletes:                      0             (0.00/sec)  (0.00/min)
>  Mod RDNs:                     0             (0.00/sec)  (0.00/min)
>  Compares:                     0             (0.00/sec)  (0.00/min)
>  Binds:                        3038          (2.56/sec)  (153.56/min)
>
>  Proxied Auth Operations:      0
>  Persistent Searches:          0
>  Internal Operations:          0
>  Entry Operations:             0
>  Extended Operations:          76
>  Abandoned Requests:           0
>  Smart Referrals Received:     0
>
>  VLV Operations:               0
>  VLV Unindexed Searches:       0
>  VLV Unindexed Components:     0
>  SORT Operations:              0
>
>  Entire Search Base Queries:   806
>  Paged Searches:               82
>  Unindexed Searches:           0
>  Unindexed Components:         8896 
You did not run logconv.pl the way I requested,
can you please run it 
again this way:

logconv.pl -ulatn  <access logs>

There should be much more important information returned from this 
tool.  Like David pointed out the unindexed search you reported above in 
fact was harmless, but that doesn't mean they all are.  The command 
above will print detailed information about each potential unindexed 
search.

I think the next step, besides gathering the right logconv output, would 
be to get several pstacks of the ns-slapd process at the same time the 
"hang" occurs.  Then we can at least see what all the threads are doing 
and hopefully get better information.  I would try and get the 
389-ds-base-debuginfo package installed first though (this should give 
us more readable pstacks).

Thanks,
Mark
>  Regards
>  Jan
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org
>  Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
>  List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
>  List Archives:
> https://lists.fedoraproject.org/archives/list/[e-mail]...