Re: 2.x query performance problem

Thierry Bordaz <tbordaz@xxxxxxxxxx> · Tue, 14 Mar 2023 19:18:08 +0100



    Hi Class,
    Indeed the same task is much faster (28 times) in 1.4.4
    [14/Mar/2023:18:57:58.984319394 +0100]
        conn=4 op=1 SRCH base="dc=example,dc=com" scope=2
filter="(uniqueMember=uid=group_entry1-0001,ou=people,dc=example,dc=com)"
        attrs="distinguishedName"

        [14/Mar/2023:18:57:59.010935256 +0100] conn=4 op=1 RESULT err=0
        tag=101 nentries=1000 wtime=0.000209520 optime=0.026622409
        etime=0.026828069
    The reason seems to be the fix
      https://github.com/389ds/389-ds-base/issues/5170 that force filter
      evaluation (even if it can be bypass) on returned entries.

      So a side effect of the fix is that when there is a large returned
      set of entries (~500 in your example) the filter evaluation is
      significant. Especially with  attribute with a large valueset
      (like uniquemember).
    The fix prevent to return invalid entries but the performance hit
      was not detected. Need to revisit this part of the fix.
    best regards

      thierry

    
    On 3/14/23 17:21, Thierry Bordaz wrote:

    
      Hi Claas,
      Good, that means that the 2x manageDSAit is now fixed. I tried
        to reproduce locally (2.x) and I think I succeeded:
      [14/Mar/2023:16:45:54.283507824 +0100]
          conn=1 op=1 SRCH base="dc=example,dc=com" scope=2
filter="(uniqueMember=uid=group_entry1-0001,ou=people,dc=example,dc=com)"
          attrs="distinguishedName"

          [14/Mar/2023:16:45:55.046440071 +0100] conn=1 op=1 RESULT
          err=0 tag=101 nentries=1000 wtime=0.000199792
          optime=0.762938352 etime=0.763134856

      
      There is 1000 groups, with each 1000 members so they are large,
        and uid=group_entry1_0001 belongs to all groups. The search last
        0.7s that is much more than what we had in 1.4 (TBC).
      Something surprising is that the server bypass the filter
        evaluation (when returning the entries). So it does not look
        like the filter contribute to the slowness.

      
      best regards

        thierry

      
      On 3/14/23 14:25, Claas Vieler wrote:

      
          Hallo Thierry,
           
          got newest version from https://github.com/389ds/389-ds-base
            dc565fd (389-Directory/2.3.2
            B2023.073.0958 )
          
            I can confirm, manageDSAit makes no difference any more
              in query time,
            got etimes with 0,9 sec after import and reindexing
              (with and without option)
             
            but a little difference to 1.4.x ist still present :) 
              ( 0.0x sec vs 0.9 sec) 
             
            thanks and best regards
            Claas
             
              
                Gesendet: Montag,
                  13. März 2023 um 17:55 Uhr

                  Von: "Thierry Bordaz" <tbordaz@xxxxxxxxxx>

                  An: 389-users@xxxxxxxxxxxxxxxxxxxxxxx

                  Betreff: [389-users] Re: 2.x query performance
                  problem
                
                  Hi Class,
                  First, thank you sooo much for your tests. This is
                    really helpful.
                  So my understanding is that this same req was
                  
                    [10, 30]ms in 1.4
                    [900, 1700]ms in 2.x
                      
                        A possibility is that the filter evaluation
                          (against the 532 returned entry) is the
                          responsible of the 1700ms (without manageDSAit
                      
                    
                  In short it looks like there is a significant
                    (>30 times slower) regression in RHDS12 vs RHDS11
                    with that testcase. In RHDS12, the handling of
                    referral adds a 2 times slower but it is possibly
                    fixed with https://github.com/389ds/389-ds-base/issues/5598.
                  best regards

                    thierry
                  On 3/13/23 17:18, Claas
                    Vieler wrote:
                  
                    
                      Hello William,
                       
                      sorry, your mail was stuck in my spam filter,
                        so I doesnt see it
                      
                        here are the logs with and without option
                          manageDSAit (as Thierry mentioned)
                         
                        
                          without manageDSAit:

                            [13/Mar/2023:16:16:06.583644293 +0100]
                            conn=32 fd=64 slot=64 connection from local
                            to
                            /var/lib/dirsrv/slapd-389ds/slapd-389ds.socket

                            [13/Mar/2023:16:16:06.586619267 +0100]
                            conn=32 AUTOBIND dn="cn=root"

                            [13/Mar/2023:16:16:06.589037720 +0100]
                            conn=32 op=0 BIND dn="cn=root" method=sasl
                            version=3 mech=EXTERNAL

                            [13/Mar/2023:16:16:06.591155242 +0100]
                            conn=32 op=0 RESULT err=0 tag=97 nentries=0
                            wtime=0.000078559 optime=0.004658221
                            etime=0.004734544 dn="cn=root"

                            [13/Mar/2023:16:16:06.591326840 +0100]
                            conn=32 op=1 SRCH base="dc=example,dc=com"
                            scope=2
                            filter="(uniqueMember=cn=testuser,ou=People,dc=example,dc=com)"
                            attrs="distinguishedName"

                            [13/Mar/2023:16:16:08.321020181 +0100]
                            conn=32 op=1 RESULT err=0 tag=101
                            nentries=532 wtime=0.000114773
                            optime=1.729694222 etime=1.729803880

                            [13/Mar/2023:16:16:08.321992532 +0100]
                            conn=32 op=2 UNBIND

                            [13/Mar/2023:16:16:08.327041073 +0100]
                            conn=32 op=2 fd=64 closed error - U1
                           
                          with manageDSAit:

                            [13/Mar/2023:16:16:22.324132867 +0100]
                            conn=33 fd=64 slot=64 connection from local
                            to
                            /var/lib/dirsrv/slapd-389ds/slapd-389ds.socket

                            [13/Mar/2023:16:16:22.326616612 +0100]
                            conn=33 AUTOBIND dn="cn=root"

                            [13/Mar/2023:16:16:22.328594648 +0100]
                            conn=33 op=0 BIND dn="cn=root" method=sasl
                            version=3 mech=EXTERNAL

                            [13/Mar/2023:16:16:22.331154393 +0100]
                            conn=33 op=0 RESULT err=0 tag=97 nentries=0
                            wtime=0.000055269 optime=0.004608598
                            etime=0.004661499 dn="cn=root"

                            [13/Mar/2023:16:16:22.331366318 +0100]
                            conn=33 op=1 SRCH base="dc=example,dc=com"
                            scope=2
                            filter="(uniqueMember=cn=testuser,ou=People,dc=expample,dc=com)"
                            attrs="distinguishedName"

                            [13/Mar/2023:16:16:23.244139238 +0100]
                            conn=33 op=2 UNBIND

                            [13/Mar/2023:16:16:23.244725555 +0100]
                            conn=33 op=1 RESULT err=0 tag=101
                            nentries=532 wtime=0.000081512
                            optime=0.913360154 etime=0.913438519

                            [1
                        
                         
                            Gesendet: Mittwoch,
                              08. März 2023 um 01:11 Uhr

                              Von: "William Brown" <william.brown@xxxxxxxx>

                              An: "389-users@xxxxxxxxxxxxxxxxxxxxxxx"
                              <389-users@xxxxxxxxxxxxxxxxxxxxxxx>

                              Betreff: [389-users] Re: 2.x query
                              performance problem
                            >

                              > Hi Claas,

                              > I do not recall a specific change
                              1.4.4 vs 2.0 that could explain this.

                              > Do you confirm that 'uniqueMember' is
                              indexed in equality on both ? What are the
                              SRCH records in the access logs (notes=A
                              ?).

                              > On 2.0, it lasts 2sec, you may try to
                              capture few pstacks that would give some
                              tips.

                              > regards

                              > thierry

                              
                              we need to see the exact filter that's
                              being used, as well as the access logs
                              lines of the slow query to really help
                              here.

                              
                              --

                              Sincerely,

                              
                              William Brown

                              
                              Senior Software Engineer,

                              Identity and Access Management

                              SUSE Labs, Australia

_______________________________________________

                              389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx

                              To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx

                              Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/

                              List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines

                              List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx

                              Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
                          
                        
                    _______________________________________________
389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx
Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue

                  
                  _______________________________________________
                  389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
                  To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
                  Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
                  List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
                  List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx
                  Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
              
            
        _______________________________________________
389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx
Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue

      
_______________________________________________
389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx
Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue