elapsed time gremlin

[Winstanley, Anthony]

Hi,
I'm hoping somebody can tell me where I might look to find why this is happening...
We're running 389-Directory/1.2.11.15 B2014.300.2010

I have two ldapsearch queries that only vary in searchbase, one which is taking too long.
(Times don't vary much with consecutive executions.)
ou=PEOPLE has just under 700,000 entries. Search takes 0-3 seconds.
ou=STUDENTS,ou=RECORDS has just under 6000 entries. Search takes 123-126 seconds.
There are no attributes used in ou=STUDENTS,ou=RECORDS that aren't also used in
ou=PEOPLE.

Two sample executions and log output:


[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b
ou=STUDENTS,ou=RECORDS,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

... 5 entries returned ...

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33505 access

[16/Feb/2017:16:31:37] conn=33505 fd=96 slot=96 SSL connection from IP1 to IP2

[16/Feb/2017:16:31:37] conn=33505 SSL 256-bit AES

[16/Feb/2017:16:31:37] conn=33505 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:31:37] conn=33505 op=0 RESULT err=0 tag=97 nentries=0 etime=0
dn="cn=directory manager"

[16/Feb/2017:16:31:37] conn=33505 op=1 SRCH
base="ou=STUDENTS,ou=RECORDS,dc=example,dc=com" scope=1
filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:33:40] conn=33505 op=1 RESULT err=4 tag=101 nentries=5 etime=123 notes=A

[16/Feb/2017:16:33:40] conn=33505 op=2 UNBIND

[16/Feb/2017:16:33:40] conn=33505 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#





[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.ca:636 -b
ou=PEOPLE,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

... 5 entries returned ...

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33578 access

[16/Feb/2017:16:38:43] conn=33578 fd=96 slot=96 SSL connection from 142.103.30.27 to
10.7.128.16

[16/Feb/2017:16:38:44] conn=33578 SSL 256-bit AES

[16/Feb/2017:16:38:44] conn=33578 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:38:44] conn=33578 op=0 RESULT err=0 tag=97 nentries=0 etime=1
dn="cn=directory manager"

[16/Feb/2017:16:38:44] conn=33578 op=1 SRCH base="ou=PEOPLE,dc=example,dc=com"
scope=1 filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:38:44] conn=33578 op=1 RESULT err=4 tag=101 nentries=5 etime=0 notes=A

[16/Feb/2017:16:38:44] conn=33578 op=2 UNBIND

[16/Feb/2017:16:38:44] conn=33578 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#


Help? This is driving me nuts... Where can I look to find out why this might be
happening?

Thanks,
Anthony

[Noriko Hosoi]

Hello,

What is the value set to nsslapd-idlistscanlimit?

$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b  
'cn=config,cn=ldbm database,cn=plugins,cn=config' -D cn=Directory\ 
Manager -w password -s base nsslapd-idlistscanlimit

If it is less than 6000, could you increase it to some large number, 
e.g., 700000, and retry the searches?

Thanks,
--noriko

On 02/16/2017 04:54 PM, Winstanley, Anthony wrote:
>  Hi,
>
>  I'm hoping somebody can tell me where I might look to find why this is 
>  happening…
>
>  We're running 389-Directory/1.2.11.15 B2014.300.2010
>
>  I have two ldapsearch queries that only vary in searchbase, one which 
>  is taking too long. (Times don't vary much with consecutive executions.)
>
>  ou=PEOPLE has just under 700,000 entries. Search takes 0-3 seconds.
>
>  ou=STUDENTS,ou=RECORDS has just under 6000 entries. Search takes 
>  123-126 seconds.
>
>  There are no attributes used in ou=STUDENTS,ou=RECORDS that aren't 
>  also used in ou=PEOPLE.
>
>  Two sample executions and log output:
>
>  [user@workstation ~]$ ldapsearch -x -LLL -H 
>  ldaps://ldap.example.com:636 -b 
>  ou=STUDENTS,ou=RECORDS,dc=example,dc=com -D cn=Directory\ Manager -w 
>  password -s one -z 5 'cn=*' dn
>
>  … 5 entries returned …
>
>  [user@workstation ~]$
>
>  [root@server slapd-ldap1]# grep conn=33505 access
>
>  [16/Feb/2017:16:31:37] conn=33505 fd=96 slot=96 SSL connection from 
>  IP1 to IP2
>
>  [16/Feb/2017:16:31:37] conn=33505 SSL 256-bit AES
>
>  [16/Feb/2017:16:31:37] conn=33505 op=0 BIND dn="cn=Directory Manager" 
>  method=128 version=3
>
>  [16/Feb/2017:16:31:37] conn=33505 op=0 RESULT err=0 tag=97 nentries=0 
>  etime=0 dn="cn=directory manager"
>
>  [16/Feb/2017:16:31:37] conn=33505 op=1 SRCH 
>  base="ou=STUDENTS,ou=RECORDS,dc=example,dc=com" scope=1 
>  filter="(cn=*)" attrs="distinguishedName"
>
>  [16/Feb/2017:16:33:40] conn=33505 op=1 RESULT err=4 tag=101 nentries=5 
>  etime=123 notes=A
>
>  [16/Feb/2017:16:33:40] conn=33505 op=2 UNBIND
>
>  [16/Feb/2017:16:33:40] conn=33505 op=2 fd=96 closed - U1
>
>  [root@server slapd-ldap1]#
>
>  [user@workstation ~]$ ldapsearch -x -LLL -H 
>  ldaps://ldap.example.ca:636 -b ou=PEOPLE,dc=example,dc=com -D 
>  cn=Directory\ Manager -w password -s one -z 5 'cn=*' dn
>
>  … 5 entries returned …
>
>  [user@workstation ~]$
>
>  [root@server slapd-ldap1]# grep conn=33578 access
>
>  [16/Feb/2017:16:38:43] conn=33578 fd=96 slot=96 SSL connection from 
>  142.103.30.27 to 10.7.128.16
>
>  [16/Feb/2017:16:38:44] conn=33578 SSL 256-bit AES
>
>  [16/Feb/2017:16:38:44] conn=33578 op=0 BIND dn="cn=Directory Manager" 
>  method=128 version=3
>
>  [16/Feb/2017:16:38:44] conn=33578 op=0 RESULT err=0 tag=97 nentries=0 
>  etime=1 dn="cn=directory manager"
>
>  [16/Feb/2017:16:38:44] conn=33578 op=1 SRCH 
>  base="ou=PEOPLE,dc=example,dc=com" scope=1 filter="(cn=*)" 
>  attrs="distinguishedName"
>
>  [16/Feb/2017:16:38:44] conn=33578 op=1 RESULT err=4 tag=101 nentries=5 
>  etime=0 notes=A
>
>  [16/Feb/2017:16:38:44] conn=33578 op=2 UNBIND
>
>  [16/Feb/2017:16:38:44] conn=33578 op=2 fd=96 closed - U1
>
>  [root@server slapd-ldap1]#
>
>  Help? This is driving me nuts… Where can I look to find out why this 
>  might be happening?
>
>  Thanks,
>
>  Anthony
>
>
>
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

[Winstanley, Anthony]

It was set to the default (4000). I set it to 700000, and now both searches are fast
(initial run time 3 seconds, then instant). And the server logs don't show any
'notes=?' for either search.

But… that's not what the docs say to do?
https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/8....

So basically, setting nsslapd-idlistscanlimit big tells the server to NOT revert to
unindexed search, and indexed search makes me happy in this case.
But why is unindexed search on ou=PEOPLE so much faster than on ou=STUDENTS,ou=RECORDS?
Or should I not care what the answer to that question is and just set
nsslapd-idlistscanlimit to a million and be happy?

Thanks for your help,
Anthony

From: Noriko Hosoi [mailto:[e-mail]]
Sent: Thursday, February 16, 2017 5:16 PM
To: 389-users(a)lists.fedoraproject.org
Subject: [389-users] Re: elapsed time gremlin

Hello,

What is the value set to nsslapd-idlistscanlimit?

$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b  'cn=config,cn=ldbm
database,cn=plugins,cn=config' -D cn=Directory\ Manager -w password -s base
nsslapd-idlistscanlimit

If it is less than 6000, could you increase it to some large number, e.g., 700000, and
retry the searches?

Thanks,
--noriko

On 02/16/2017 04:54 PM, Winstanley, Anthony wrote:
Hi,
I'm hoping somebody can tell me where I might look to find why this is happening…
We're running 389-Directory/1.2.11.15 B2014.300.2010

I have two ldapsearch queries that only vary in searchbase, one which is taking too long.
(Times don't vary much with consecutive executions.)
ou=PEOPLE has just under 700,000 entries. Search takes 0-3 seconds.
ou=STUDENTS,ou=RECORDS has just under 6000 entries. Search takes 123-126 seconds.
There are no attributes used in ou=STUDENTS,ou=RECORDS that aren't also used in
ou=PEOPLE.

Two sample executions and log output:


[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b
ou=STUDENTS,ou=RECORDS,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

… 5 entries returned …

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33505 access

[16/Feb/2017:16:31:37] conn=33505 fd=96 slot=96 SSL connection from IP1 to IP2

[16/Feb/2017:16:31:37] conn=33505 SSL 256-bit AES

[16/Feb/2017:16:31:37] conn=33505 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:31:37] conn=33505 op=0 RESULT err=0 tag=97 nentries=0 etime=0
dn="cn=directory manager"

[16/Feb/2017:16:31:37] conn=33505 op=1 SRCH
base="ou=STUDENTS,ou=RECORDS,dc=example,dc=com" scope=1
filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:33:40] conn=33505 op=1 RESULT err=4 tag=101 nentries=5 etime=123 notes=A

[16/Feb/2017:16:33:40] conn=33505 op=2 UNBIND

[16/Feb/2017:16:33:40] conn=33505 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#





[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.ca:636 -b
ou=PEOPLE,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

… 5 entries returned …

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33578 access

[16/Feb/2017:16:38:43] conn=33578 fd=96 slot=96 SSL connection from 142.103.30.27 to
10.7.128.16

[16/Feb/2017:16:38:44] conn=33578 SSL 256-bit AES

[16/Feb/2017:16:38:44] conn=33578 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:38:44] conn=33578 op=0 RESULT err=0 tag=97 nentries=0 etime=1
dn="cn=directory manager"

[16/Feb/2017:16:38:44] conn=33578 op=1 SRCH base="ou=PEOPLE,dc=example,dc=com"
scope=1 filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:38:44] conn=33578 op=1 RESULT err=4 tag=101 nentries=5 etime=0 notes=A

[16/Feb/2017:16:38:44] conn=33578 op=2 UNBIND

[16/Feb/2017:16:38:44] conn=33578 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#


Help? This is driving me nuts… Where can I look to find out why this might be happening?

Thanks,
Anthony




_______________________________________________

389-users mailing list --
[e-mail]<mailto:[e-mail]>

To unsubscribe send an email to
[e-mail]<mailto:[e-mail]>

[Noriko Hosoi]

On 02/17/2017 07:42 AM, Winstanley, Anthony wrote:
>  It was set to the default (4000). I set it to 700000, and now both 
>  searches are fast (initial run time 3 seconds, then instant). And the 
>  server logs don't show any 'notes=?' for either search.
>
>  But… that's not what the docs say to do?
>
>
> https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/8....
>  
Glad to hear it improved the performance.

BTW, please refer a newer Doc.  There are lots of enhancements and bug 
fixes since the RHDS8.2 time frame...

RHDS 10 Performance Tuning Guide
https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/10...


    5.3. Setting Index Scan Limits

In large directories, the search results list can get huge. A directory 
with a million |inetorgperson| entries would have a million entries that 
were returned with a filter like |(objectclass=inetorgperson)|, and an 
index for the /|sn|/ attribute would have at least a million entries in it.
Loading a long ID list from the database significantly reduces search 
performance. *The configuration parameter, 
**|nsslapd-idlistscanlimit|**, sets a limit on the number of IDs that 
are read before a key is considered to match the entire primary index 
(meaning the search is treated as an unindexed search with a different 
set of resource limits). *
>  So basically, setting nsslapd-idlistscanlimit big tells the server to 
>  NOT revert to unindexed search, and indexed search makes me happy in 
>  this case.
>
>  But why is unindexed search on ou=PEOPLE so much faster than on 
>  ou=STUDENTS,ou=RECORDS?
>  
If you get the entire 70000 ou=PEOPLE entries, it'd also take long time, 
I'd think.  If the search goes to the unindexed search, it scans all the 
entries in the database one by one and checks if it satisfies the search 
condition.  Probably, OU=PEOPLE entries are put at the older part of the 
database (having lower entry id's) and OU=STUDENTS entries are placed 
after that (with higher entry id's)? If that's the case, you cannot get 
the OU=STUDENTS entries unless you finish scanning OU=PEOPLE entries.

If indexed, you don't have to scan them but get the entry id list via 
indexes.

Hope it helps.
--noriko
>  Or should I not care what the answer to that question is and just set 
>  nsslapd-idlistscanlimit to a million and be happy?
>
>  Thanks for your help,
>
>  Anthony
>
>  *From:*Noriko Hosoi [mailto:[e-mail]]
>  *Sent:* Thursday, February 16, 2017 5:16 PM
>  *To:* 389-users(a)lists.fedoraproject.org
>  *Subject:* [389-users] Re: elapsed time gremlin
>
>  Hello,
>
>  What is the value set to nsslapd-idlistscanlimit?
>
>  $ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b  
>  'cn=config,cn=ldbm database,cn=plugins,cn=config' -D cn=Directory\ 
>  Manager -w password -s base nsslapd-idlistscanlimit
>
>  If it is less than 6000, could you increase it to some large number, 
>  e.g., 700000, and retry the searches?
>
>  Thanks,
>  --noriko
>
>  On 02/16/2017 04:54 PM, Winstanley, Anthony wrote:
>
>      Hi,
>
>      I'm hoping somebody can tell me where I might look to find why
>      this is happening…
>
>      We're running 389-Directory/1.2.11.15 B2014.300.2010
>
>      I have two ldapsearch queries that only vary in searchbase, one
>      which is taking too long. (Times don't vary much with consecutive
>      executions.)
>
>      ou=PEOPLE has just under 700,000 entries. Search takes 0-3 seconds.
>
>      ou=STUDENTS,ou=RECORDS has just under 6000 entries. Search takes
>      123-126 seconds.
>
>      There are no attributes used in ou=STUDENTS,ou=RECORDS that aren't
>      also used in ou=PEOPLE.
>
>      Two sample executions and log output:
>
>      [user@workstation ~]$ ldapsearch -x -LLL -H
>      ldaps://ldap.example.com:636 -b
>      ou=STUDENTS,ou=RECORDS,dc=example,dc=com -D cn=Directory\ Manager
>      -w password -s one -z 5 'cn=*' dn
>
>      … 5 entries returned …
>
>      [user@workstation ~]$
>
>      [root@server slapd-ldap1]# grep conn=33505 access
>
>      [16/Feb/2017:16:31:37] conn=33505 fd=96 slot=96 SSL connection
>      from IP1 to IP2
>
>      [16/Feb/2017:16:31:37] conn=33505 SSL 256-bit AES
>
>      [16/Feb/2017:16:31:37] conn=33505 op=0 BIND dn="cn=Directory
>      Manager" method=128 version=3
>
>      [16/Feb/2017:16:31:37] conn=33505 op=0 RESULT err=0 tag=97
>      nentries=0 etime=0 dn="cn=directory manager"
>
>      [16/Feb/2017:16:31:37] conn=33505 op=1 SRCH
>      base="ou=STUDENTS,ou=RECORDS,dc=example,dc=com" scope=1
>      filter="(cn=*)" attrs="distinguishedName"
>
>      [16/Feb/2017:16:33:40] conn=33505 op=1 RESULT err=4 tag=101
>      nentries=5 etime=123 notes=A
>
>      [16/Feb/2017:16:33:40] conn=33505 op=2 UNBIND
>
>      [16/Feb/2017:16:33:40] conn=33505 op=2 fd=96 closed - U1
>
>      [root@server slapd-ldap1]#
>
>      [user@workstation ~]$ ldapsearch -x -LLL -H
>      ldaps://ldap.example.ca:636 -b ou=PEOPLE,dc=example,dc=com -D
>      cn=Directory\ Manager -w password -s one -z 5 'cn=*' dn
>
>      … 5 entries returned …
>
>      [user@workstation ~]$
>
>      [root@server slapd-ldap1]# grep conn=33578 access
>
>      [16/Feb/2017:16:38:43] conn=33578 fd=96 slot=96 SSL connection
>      from 142.103.30.27 to 10.7.128.16
>
>      [16/Feb/2017:16:38:44] conn=33578 SSL 256-bit AES
>
>      [16/Feb/2017:16:38:44] conn=33578 op=0 BIND dn="cn=Directory
>      Manager" method=128 version=3
>
>      [16/Feb/2017:16:38:44] conn=33578 op=0 RESULT err=0 tag=97
>      nentries=0 etime=1 dn="cn=directory manager"
>
>      [16/Feb/2017:16:38:44] conn=33578 op=1 SRCH
>      base="ou=PEOPLE,dc=example,dc=com" scope=1 filter="(cn=*)"
>      attrs="distinguishedName"
>
>      [16/Feb/2017:16:38:44] conn=33578 op=1 RESULT err=4 tag=101
>      nentries=5 etime=0 notes=A
>
>      [16/Feb/2017:16:38:44] conn=33578 op=2 UNBIND
>
>      [16/Feb/2017:16:38:44] conn=33578 op=2 fd=96 closed - U1
>
>      [root@server slapd-ldap1]#
>
>      Help? This is driving me nuts… Where can I look to find out why
>      this might be happening?
>
>      Thanks,
>
>      Anthony
>
>
>
>
>      _______________________________________________
>
>      389-users mailing list --389-users(a)lists.fedoraproject.org
>      <mailto:[e-mail]>
>
>      To unsubscribe send an email to389-users-leave(a)lists.fedoraproject.org
>      <mailto:[e-mail]>
>
>
>
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

[Winstanley, Anthony]

Thanks, that helps. :)

Anthony

From: Noriko Hosoi [mailto:[e-mail]]
Sent: Friday, February 17, 2017 10:43 AM
To: 389-users(a)lists.fedoraproject.org
Subject: [389-users] Re: elapsed time gremlin

On 02/17/2017 07:42 AM, Winstanley, Anthony wrote:
It was set to the default (4000). I set it to 700000, and now both searches are fast
(initial run time 3 seconds, then instant). And the server logs don't show any
'notes=?' for either search.

But... that's not what the docs say to do?
https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/8....
Glad to hear it improved the performance.

BTW, please refer a newer Doc.  There are lots of enhancements and bug fixes since the
RHDS8.2 time frame...

RHDS 10 Performance Tuning Guide
https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/10...
5.3. Setting Index Scan Limits
In large directories, the search results list can get huge. A directory with a million
inetorgperson entries would have a million entries that were returned with a filter like
(objectclass=inetorgperson), and an index for the sn attribute would have at least a
million entries in it.
Loading a long ID list from the database significantly reduces search performance. The
configuration parameter, nsslapd-idlistscanlimit, sets a limit on the number of IDs that
are read before a key is considered to match the entire primary index (meaning the search
is treated as an unindexed search with a different set of resource limits).

So basically, setting nsslapd-idlistscanlimit big tells the server to NOT revert to
unindexed search, and indexed search makes me happy in this case.
But why is unindexed search on ou=PEOPLE so much faster than on ou=STUDENTS,ou=RECORDS?
If you get the entire 70000 ou=PEOPLE entries, it'd also take long time, I'd
think.  If the search goes to the unindexed search, it scans all the entries in the
database one by one and checks if it satisfies the search condition.  Probably, OU=PEOPLE
entries are put at the older part of the database (having lower entry id's) and
OU=STUDENTS entries are placed after that (with higher entry id's)?  If that's the
case, you cannot get the OU=STUDENTS entries unless you finish scanning OU=PEOPLE
entries.

If indexed, you don't have to scan them but get the entry id list via indexes.

Hope it helps.
--noriko

Or should I not care what the answer to that question is and just set
nsslapd-idlistscanlimit to a million and be happy?

Thanks for your help,
Anthony

From: Noriko Hosoi [mailto:[e-mail]]
Sent: Thursday, February 16, 2017 5:16 PM
To: [e-mail]<mailto:[e-mail]>
Subject: [389-users] Re: elapsed time gremlin

Hello,

What is the value set to nsslapd-idlistscanlimit?

$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b  'cn=config,cn=ldbm
database,cn=plugins,cn=config' -D cn=Directory\ Manager -w password -s base
nsslapd-idlistscanlimit

If it is less than 6000, could you increase it to some large number, e.g., 700000, and
retry the searches?

Thanks,
--noriko

On 02/16/2017 04:54 PM, Winstanley, Anthony wrote:
Hi,
I'm hoping somebody can tell me where I might look to find why this is happening...
We're running 389-Directory/1.2.11.15 B2014.300.2010

I have two ldapsearch queries that only vary in searchbase, one which is taking too long.
(Times don't vary much with consecutive executions.)
ou=PEOPLE has just under 700,000 entries. Search takes 0-3 seconds.
ou=STUDENTS,ou=RECORDS has just under 6000 entries. Search takes 123-126 seconds.
There are no attributes used in ou=STUDENTS,ou=RECORDS that aren't also used in
ou=PEOPLE.

Two sample executions and log output:


[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b
ou=STUDENTS,ou=RECORDS,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

... 5 entries returned ...

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33505 access

[16/Feb/2017:16:31:37] conn=33505 fd=96 slot=96 SSL connection from IP1 to IP2

[16/Feb/2017:16:31:37] conn=33505 SSL 256-bit AES

[16/Feb/2017:16:31:37] conn=33505 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:31:37] conn=33505 op=0 RESULT err=0 tag=97 nentries=0 etime=0
dn="cn=directory manager"

[16/Feb/2017:16:31:37] conn=33505 op=1 SRCH
base="ou=STUDENTS,ou=RECORDS,dc=example,dc=com" scope=1
filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:33:40] conn=33505 op=1 RESULT err=4 tag=101 nentries=5 etime=123 notes=A

[16/Feb/2017:16:33:40] conn=33505 op=2 UNBIND

[16/Feb/2017:16:33:40] conn=33505 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#





[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.ca:636 -b
ou=PEOPLE,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

... 5 entries returned ...

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33578 access

[16/Feb/2017:16:38:43] conn=33578 fd=96 slot=96 SSL connection from 142.103.30.27 to
10.7.128.16

[16/Feb/2017:16:38:44] conn=33578 SSL 256-bit AES

[16/Feb/2017:16:38:44] conn=33578 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:38:44] conn=33578 op=0 RESULT err=0 tag=97 nentries=0 etime=1
dn="cn=directory manager"

[16/Feb/2017:16:38:44] conn=33578 op=1 SRCH base="ou=PEOPLE,dc=example,dc=com"
scope=1 filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:38:44] conn=33578 op=1 RESULT err=4 tag=101 nentries=5 etime=0 notes=A

[16/Feb/2017:16:38:44] conn=33578 op=2 UNBIND

[16/Feb/2017:16:38:44] conn=33578 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#


Help? This is driving me nuts... Where can I look to find out why this might be
happening?

Thanks,
Anthony





_______________________________________________

389-users mailing list --
[e-mail]<mailto:[e-mail]>

To unsubscribe send an email to
[e-mail]<mailto:[e-mail]>






_______________________________________________

389-users mailing list --
[e-mail]<mailto:[e-mail]>

To unsubscribe send an email to
[e-mail]<mailto:[e-mail]>

[Fong, Trevor]

Can we set nsIDListScanLimit=70000 (or whatever) for a service account instead of changing
the system nsslapd-idlistscanlimit setting?

Thanks,
Trev


From: Anthony Winstanley <winstan(a)cs.ubc.ca&gt;
Reply-To: &quot;389-users(a)lists.fedoraproject.org&quot;
<389-users(a)lists.fedoraproject.org&gt;
Date: Friday, February 17, 2017 at 12:37 PM
To: &quot;389-users(a)lists.fedoraproject.org&quot;
<389-users(a)lists.fedoraproject.org&gt;
Subject: [389-users] Re: elapsed time gremlin

Thanks, that helps. ☺

Anthony

From: Noriko Hosoi [mailto:[e-mail]]
Sent: Friday, February 17, 2017 10:43 AM
To: 389-users(a)lists.fedoraproject.org
Subject: [389-users] Re: elapsed time gremlin

On 02/17/2017 07:42 AM, Winstanley, Anthony wrote:
It was set to the default (4000). I set it to 700000, and now both searches are fast
(initial run time 3 seconds, then instant). And the server logs don't show any
'notes=?' for either search.

But… that's not what the docs say to do?
https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/8....
Glad to hear it improved the performance.

BTW, please refer a newer Doc.  There are lots of enhancements and bug fixes since the
RHDS8.2 time frame...

RHDS 10 Performance Tuning Guide
https://access.redhat.com/documentation/en-US/Red_Hat_Directory_Server/10...
5.3. Setting Index Scan Limits
In large directories, the search results list can get huge. A directory with a million
inetorgperson entries would have a million entries that were returned with a filter like
(objectclass=inetorgperson), and an index for the sn attribute would have at least a
million entries in it.
Loading a long ID list from the database significantly reduces search performance. The
configuration parameter, nsslapd-idlistscanlimit, sets a limit on the number of IDs that
are read before a key is considered to match the entire primary index (meaning the search
is treated as an unindexed search with a different set of resource limits).

So basically, setting nsslapd-idlistscanlimit big tells the server to NOT revert to
unindexed search, and indexed search makes me happy in this case.
But why is unindexed search on ou=PEOPLE so much faster than on ou=STUDENTS,ou=RECORDS?
If you get the entire 70000 ou=PEOPLE entries, it'd also take long time, I'd
think.  If the search goes to the unindexed search, it scans all the entries in the
database one by one and checks if it satisfies the search condition.  Probably, OU=PEOPLE
entries are put at the older part of the database (having lower entry id's) and
OU=STUDENTS entries are placed after that (with higher entry id's)?  If that's the
case, you cannot get the OU=STUDENTS entries unless you finish scanning OU=PEOPLE
entries.

If indexed, you don't have to scan them but get the entry id list via indexes.

Hope it helps.
--noriko


Or should I not care what the answer to that question is and just set
nsslapd-idlistscanlimit to a million and be happy?

Thanks for your help,
Anthony

From: Noriko Hosoi [mailto:[e-mail]]
Sent: Thursday, February 16, 2017 5:16 PM
To: [e-mail]<mailto:[e-mail]>
Subject: [389-users] Re: elapsed time gremlin

Hello,

What is the value set to nsslapd-idlistscanlimit?

$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b  'cn=config,cn=ldbm
database,cn=plugins,cn=config' -D cn=Directory\ Manager -w password -s base
nsslapd-idlistscanlimit

If it is less than 6000, could you increase it to some large number, e.g., 700000, and
retry the searches?

Thanks,
--noriko

On 02/16/2017 04:54 PM, Winstanley, Anthony wrote:
Hi,
I'm hoping somebody can tell me where I might look to find why this is happening…
We're running 389-Directory/1.2.11.15 B2014.300.2010

I have two ldapsearch queries that only vary in searchbase, one which is taking too long.
(Times don't vary much with consecutive executions.)
ou=PEOPLE has just under 700,000 entries. Search takes 0-3 seconds.
ou=STUDENTS,ou=RECORDS has just under 6000 entries. Search takes 123-126 seconds.
There are no attributes used in ou=STUDENTS,ou=RECORDS that aren't also used in
ou=PEOPLE.

Two sample executions and log output:


[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b
ou=STUDENTS,ou=RECORDS,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

… 5 entries returned …

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33505 access

[16/Feb/2017:16:31:37] conn=33505 fd=96 slot=96 SSL connection from IP1 to IP2

[16/Feb/2017:16:31:37] conn=33505 SSL 256-bit AES

[16/Feb/2017:16:31:37] conn=33505 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:31:37] conn=33505 op=0 RESULT err=0 tag=97 nentries=0 etime=0
dn="cn=directory manager"

[16/Feb/2017:16:31:37] conn=33505 op=1 SRCH
base="ou=STUDENTS,ou=RECORDS,dc=example,dc=com" scope=1
filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:33:40] conn=33505 op=1 RESULT err=4 tag=101 nentries=5 etime=123 notes=A

[16/Feb/2017:16:33:40] conn=33505 op=2 UNBIND

[16/Feb/2017:16:33:40] conn=33505 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#





[user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.ca:636 -b
ou=PEOPLE,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
'cn=*' dn

… 5 entries returned …

[user@workstation ~]$

[root@server slapd-ldap1]# grep conn=33578 access

[16/Feb/2017:16:38:43] conn=33578 fd=96 slot=96 SSL connection from 142.103.30.27 to
10.7.128.16

[16/Feb/2017:16:38:44] conn=33578 SSL 256-bit AES

[16/Feb/2017:16:38:44] conn=33578 op=0 BIND dn="cn=Directory Manager" method=128
version=3

[16/Feb/2017:16:38:44] conn=33578 op=0 RESULT err=0 tag=97 nentries=0 etime=1
dn="cn=directory manager"

[16/Feb/2017:16:38:44] conn=33578 op=1 SRCH base="ou=PEOPLE,dc=example,dc=com"
scope=1 filter="(cn=*)" attrs="distinguishedName"

[16/Feb/2017:16:38:44] conn=33578 op=1 RESULT err=4 tag=101 nentries=5 etime=0 notes=A

[16/Feb/2017:16:38:44] conn=33578 op=2 UNBIND

[16/Feb/2017:16:38:44] conn=33578 op=2 fd=96 closed - U1

[root@server slapd-ldap1]#


Help? This is driving me nuts… Where can I look to find out why this might be happening?

Thanks,
Anthony






_______________________________________________

389-users mailing list --
[e-mail]<mailto:[e-mail]>

To unsubscribe send an email to
[e-mail]<mailto:[e-mail]>







_______________________________________________

389-users mailing list --
[e-mail]<mailto:[e-mail]>

To unsubscribe send an email to
[e-mail]<mailto:[e-mail]>

[William Brown]

On Fri, 2017-02-17 at 00:54 +0000, Winstanley, Anthony wrote:
>  Hi,
>  I'm hoping somebody can tell me where I might look to find why this is happening...
>  We're running 389-Directory/1.2.11.15 B2014.300.2010
>  
>  I have two ldapsearch queries that only vary in searchbase, one which is taking too long.
> (Times don't vary much with consecutive executions.)
>  ou=PEOPLE has just under 700,000 entries. Search takes 0-3 seconds.
>  ou=STUDENTS,ou=RECORDS has just under 6000 entries. Search takes 123-126 seconds.
>  There are no attributes used in ou=STUDENTS,ou=RECORDS that aren't also used in
> ou=PEOPLE. 
Both of those queries are notes=A. This means they are fully unindexed! 

Please add indexes for the filter used in the search terms, then run
db2index to make sure they are updated and inplace. 

That will probably help you a lot .... 

>  
>  Two sample executions and log output:
>  
>  
>  [user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.com:636 -b
> ou=STUDENTS,ou=RECORDS,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
> 'cn=*' dn
>  
>  ... 5 entries returned ...
>  
>  [user@workstation ~]$
>  
>  [root@server slapd-ldap1]# grep conn=33505 access
>  
>  [16/Feb/2017:16:31:37] conn=33505 fd=96 slot=96 SSL connection from IP1 to IP2
>  
>  [16/Feb/2017:16:31:37] conn=33505 SSL 256-bit AES
>  
>  [16/Feb/2017:16:31:37] conn=33505 op=0 BIND dn="cn=Directory Manager"
> method=128 version=3
>  
>  [16/Feb/2017:16:31:37] conn=33505 op=0 RESULT err=0 tag=97 nentries=0 etime=0
> dn="cn=directory manager"
>  
>  [16/Feb/2017:16:31:37] conn=33505 op=1 SRCH
> base="ou=STUDENTS,ou=RECORDS,dc=example,dc=com" scope=1
> filter="(cn=*)" attrs="distinguishedName"
>  
>  [16/Feb/2017:16:33:40] conn=33505 op=1 RESULT err=4 tag=101 nentries=5 etime=123 notes=A
>  
>  [16/Feb/2017:16:33:40] conn=33505 op=2 UNBIND
>  
>  [16/Feb/2017:16:33:40] conn=33505 op=2 fd=96 closed - U1
>  
>  [root@server slapd-ldap1]#
>  
>  
>  
>  
>  
>  [user@workstation ~]$ ldapsearch -x -LLL -H ldaps://ldap.example.ca:636 -b
> ou=PEOPLE,dc=example,dc=com -D cn=Directory\ Manager -w password -s one -z 5
> 'cn=*' dn
>  
>  ... 5 entries returned ...
>  
>  [user@workstation ~]$
>  
>  [root@server slapd-ldap1]# grep conn=33578 access
>  
>  [16/Feb/2017:16:38:43] conn=33578 fd=96 slot=96 SSL connection from 142.103.30.27 to
> 10.7.128.16
>  
>  [16/Feb/2017:16:38:44] conn=33578 SSL 256-bit AES
>  
>  [16/Feb/2017:16:38:44] conn=33578 op=0 BIND dn="cn=Directory Manager"
> method=128 version=3
>  
>  [16/Feb/2017:16:38:44] conn=33578 op=0 RESULT err=0 tag=97 nentries=0 etime=1
> dn="cn=directory manager"
>  
>  [16/Feb/2017:16:38:44] conn=33578 op=1 SRCH base="ou=PEOPLE,dc=example,dc=com"
> scope=1 filter="(cn=*)" attrs="distinguishedName"
>  
>  [16/Feb/2017:16:38:44] conn=33578 op=1 RESULT err=4 tag=101 nentries=5 etime=0 notes=A
>  
>  [16/Feb/2017:16:38:44] conn=33578 op=2 UNBIND
>  
>  [16/Feb/2017:16:38:44] conn=33578 op=2 fd=96 closed - U1
>  
>  [root@server slapd-ldap1]#
>  
>  
>  Help? This is driving me nuts... Where can I look to find out why this might be
> happening?
>  
>  Thanks,
>  Anthony
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org 
-- 
Sincerely,

William Brown
Software Engineer
Red Hat, Brisbane