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
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
>
<
https://github.com/389ds/389-ds-base/commit/dc565fdacbde6e1fd333213d707aa...
> 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(a)redhat.com>
> *An:* 389-users(a)lists.fedoraproject.org
> *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
> o 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(a)suse.com>
> *An:* "389-users(a)lists.fedoraproject.org"
> <389-users(a)lists.fedoraproject.org>
> *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(a)lists.fedoraproject.org
> To unsubscribe send an email to
> 389-users-leave(a)lists.fedoraproject.org
> 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@lists.fedoraproje...
> Do not reply to spam, report it:
>
https://pagure.io/fedora-infrastructure/new_issue
>
> _______________________________________________
> 389-users mailing list --389-users(a)lists.fedoraproject.org
> To unsubscribe send an email to389-users-leave(a)lists.fedoraproject.org
> 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@lists.fe...
> Do not reply to spam, report
it:https://pagure.io/fedora-infrastructure/new_issue
>
> _______________________________________________ 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://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@lists.fedoraproje...
> Do not reply to spam, report it:
>
https://pagure.io/fedora-infrastructure/new_issue
>
> _______________________________________________
> 389-users mailing list --389-users(a)lists.fedoraproject.org
> To unsubscribe send an email to389-users-leave(a)lists.fedoraproject.org
> 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@lists.fe...
> Do not reply to spam, report it:https://pagure.io/fedora-infrastructure/new_issue