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
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 regardsClaasGesendet: Montag, 13. März 2023 um 17:55 Uhr
Von: "Thierry Bordaz" <tbordaz@redhat.com>
An: 389-users@lists.fedoraproject.org
Betreff: [389-users] Re: 2.x query performance problemHi 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
thierryOn 3/13/23 17:18, Claas Vieler wrote:_______________________________________________ 389-users mailing list -- 389-users@lists.fedoraproject.org To unsubscribe send an email to 389-users-leave@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.fedoraproject.org Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issueHello William,sorry, your mail was stuck in my spam filter, so I doesnt see ithere 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 - U1with 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
[1Gesendet: Mittwoch, 08. März 2023 um 01:11 Uhr
Von: "William Brown" <william.brown@suse.com>
An: "389-users@lists.fedoraproject.org" <389-users@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@lists.fedoraproject.org
To unsubscribe send an email to 389-users-leave@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.fedoraproject.org
Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue_______________________________________________ 389-users mailing list -- 389-users@lists.fedoraproject.org To unsubscribe send an email to 389-users-leave@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.fedoraproject.org Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
_______________________________________________ 389-users mailing list -- 389-users@lists.fedoraproject.org To unsubscribe send an email to 389-users-leave@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.fedoraproject.org Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
No comments:
Post a Comment