Issue 9190 - Limits being applied to rootdn incorrectly
Summary: Limits being applied to rootdn incorrectly
Status: UNCONFIRMED
Alias: None
Product: OpenLDAP
Classification: Unclassified
Component: slapd (show other issues)
Version: 2.4.48
Hardware: All All
: --- normal
Target Milestone: ---
Assignee: OpenLDAP project
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-03-21 22:45 UTC by Quanah Gibson-Mount
Modified: 2020-03-23 16:59 UTC (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this issue.
Description Quanah Gibson-Mount 2020-03-21 22:45:37 UTC
With the following, seeing the global limit (50) being applied to the database rootdn.

Relevant config pieces:

sizelimit 50


...

database mdb
...
rootdn cn=admin,dc=xxx,dc=yyy
limits dn.exact="cn=admin,dc=xxx,dc=yyy" size=unlimited time=unlimited


However, we *sometimes* see a sizelimit error:

Mar 20 22:05:47 localhost slapd[30041]: conn=1059 fd=23 ACCEPT from IP=xx.yy.zz.aa:35621 (IP=0.0.0.0:389)
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=0 BIND dn="cn=admin,dc=xxx,dc=yyy" method=128
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=0 BIND dn="cn=admin,dc=xxx,dc=yyy" mech=SIMPLE ssf=0
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=0 RESULT tag=97 err=0 qtime=0.000017 etime=0.576530 text=
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=1 SRCH attr=namingContexts
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=1 SEARCH RESULT tag=101 err=0 qtime=0.000019 etime=0.595522 nentries=1 text=
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=2 SRCH base="dc=xxx,dc=yyy" scope=2 deref=0 filter="(uid=*)"
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=2 SEARCH RESULT tag=101 err=4 qtime=0.000019 etime=0.614634 nentries=1 text=
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 op=3 UNBIND
Mar 20 22:05:47 localhost slapd[30041]: conn=1059 fd=23 closed
Comment 1 Quanah Gibson-Mount 2020-03-21 22:49:04 UTC
I've tried reproducing via a script, and while I get the same searches, I do not get the err=4.  The difference seems to be the fact that when the error is seen, the system is under load with multiple connections and searches occurring, while my test is while the system is idle.  It makes me wonder if this is an initialization bug similar to bug#9052.

Mar 21 22:44:32 localhost slapd[30041]: conn=2623 fd=23 ACCEPT from IP=xx.yyy.zz.aa:38002 (IP=0.0.0.0:389)
Mar 21 22:44:32 localhost slapd[30041]: conn=2623 op=0 BIND dn="cn=admin,dc=xxx,dc=yyy" method=128
Mar 21 22:44:32 localhost slapd[30041]: conn=2623 op=0 BIND dn="cn=admin,dc=xxx,dc=yyy" mech=SIMPLE ssf=0
Mar 21 22:44:32 localhost slapd[30041]: conn=2623 op=0 RESULT tag=97 err=0 qtime=0.000017 etime=0.671021 text=
Mar 21 22:44:32 localhost slapd[30041]: conn=2623 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Mar 21 22:44:32 localhost slapd[30041]: conn=2623 op=1 SRCH attr=namingContexts
Mar 21 22:44:32 localhost slapd[30041]: conn=2623 op=1 SEARCH RESULT tag=101 err=0 qtime=0.000034 etime=0.675941 nentries=1 text=
Mar 21 22:44:32 localhost slapd[30041]: conn=2623 op=2 SRCH base="dc=xxx,dc=yyy" scope=2 deref=0 filter="(uid=*)"

(search continues until I kill it, as we clearly never hit the size limit)
Comment 2 Quanah Gibson-Mount 2020-03-21 22:53:07 UTC
Looking at the logs, this always happens when the PRIOR usage of the file descriptor was closed due to an idletimeout
Comment 3 Quanah Gibson-Mount 2020-03-21 23:38:31 UTC
As an aside, idletimeout does not appear to be functioning correctly.  On the dev system, have set a 300 second idletimeout:

idletimeout     300

which is 5 minutes.

a) Connect at 23:24:37, go idle:

Mar 21 23:24:37 ldapdev0 slapd[71056]: conn=1003 fd=23 ACCEPT from IP=xx.yy.zz.aa:57006 (IP=0.0.0.0:389)


b) have a connection connect after 5 minutes, 10 seconds.  This should force the cleanup routine to drop the connection, but this is not what I see:

Mar 21 23:29:49 ldapdev0 slapd[71056]: conn=1004 fd=24 ACCEPT from IP=xx.yy.zz.aa:58508 (IP=0.0.0.0:389)

This is clearly 5 minutes, 12 seconds later -- connection was not dropped, but it should have been.

c) My test connection, which is supposed to reuse the file descriptor in (a) does not do this, when it connects at:

Mar 21 23:30:37 ldapdev0 slapd[71056]: conn=1005 fd=24 ACCEPT from IP=xx.yy.zz.aa:58742 (IP=0.0.0.0:389)


In fact, the connection does not get dropped until:

Mar 21 23:31:52 ldapdev0 slapd[71056]: conn=1003 fd=23 closed (idletimeout)

Nearly 7.5 minutes later.
Comment 4 Howard Chu 2020-03-23 16:59:37 UTC
(In reply to Quanah Gibson-Mount from comment #3)
> As an aside, idletimeout does not appear to be functioning correctly.  On
> the dev system, have set a 300 second idletimeout:
> 
> idletimeout     300
> 
> which is 5 minutes.

> In fact, the connection does not get dropped until:
> 
> Mar 21 23:31:52 ldapdev0 slapd[71056]: conn=1003 fd=23 closed (idletimeout)
> 
> Nearly 7.5 minutes later.

Working as designed. It only checks timeouts every timeout/4 seconds; doing so more frequently was considered too expensive.