#559 Chainingbackend fails with "Insufficient access" error=50 when it passes the connection limit
Closed: wontfix None Opened 9 years ago by nhosoi.

It looks chaining backend has an issue. Some connection is established and used for operations without binding. Search is allowed, but delete is rejected as expected with the acl settings.

This is the snippet of the access log. conn=15 is established and used immediately for search without binding. The searches are from ldclt. Then, the same connection is used for ldclt delete, which fails since acl does not allow it to anonymous (no bind user).

[] conn=15 fd=64 slot=64 connection from 10.16.66.124 to 10.16.66.124
[] conn=15 op=0 SRCH base="o=farm1,o=cbrLD.com" scope=2 filter="(cn=monsieur14394)" attrs=ALL authzid="uid=buser,o=cbrld.com"
[] conn=15 op=0 RESULT err=0 tag=101 nentries=0 etime=0
[] conn=15 op=1 SRCH base="o=farm1,o=cbrLD.com" scope=2 filter="(cn=monsieur22398)" attrs=ALL authzid="uid=buser,o=cbrld.com"
[] conn=15 op=1 RESULT err=0 tag=101 nentries=0 etime=0
[] conn=15 op=2 SRCH base="o=farm1,o=cbrLD.com" scope=2 filter="(cn=monsieur12018)" attrs=ALL authzid="uid=buser,o=cbrld.com"
...
[] conn=15 op=48176 DEL dn="cn=monsieur00000,o=farm1,o=cbrLD.com" authzid="uid=buser,o=cbrld.com"
[] conn=15 op=48176 RESULT err=50 tag=107 nentries=0 etime=0
...
[] conn=15 op=48188 DEL dn="cn=monsieur00005,o=farm1,o=cbrLD.com" authzid="uid=buser,o=cbrld.com"
[] conn=15 op=48188 RESULT err=50 tag=107 nentries=0 etime=1

On farm1, all the err=50 are associated with conn=15.

egrep err=50 access | egrep -v "conn=15"

On farm2, all the err=50 are associated with conn=16.

egrep err=50 access | egrep -v "conn=16"

This is the error log and access log of one delete op. It shows the binddn is empty.

# egrep "conn=15 op=48188" access errors
access:[] conn=15 op=48188 DEL dn="cn=monsieur00005,o=farm1,o=cbrLD.com" authzid="uid=buser,o=cbrld.com"
access:[] conn=15 op=48188 RESULT err=50 tag=107 nentries=0 etime=1
errors:[] NSACLPlugin - #### conn=15 op=48188 binddn=""
errors:[] NSACLPlugin - #### conn=15 op=48188 binddn=""
errors:[] NSACLPlugin - conn=15 op=48188 (main): Deny proxy on entry(cn=monsieur00005,o=farm1,o=cbrld.com).attr(NULL) to anonymous: no aci matched the subject by aci(19): aciname= "troot", acidn="o=cbrld.com"
errors:[] NSACLPlugin - conn=15 op=48188 (main): Deny delete on entry(cn=monsieur00005,o=farm1,o=cbrld.com).attr(NULL) to proxy (uid=buser,o=cbrld.com): error occurred

I grepped BIND in the access log on Farm1. conn=13 and 15 are missing, which were running w/o bind.

# egrep BIND access | egrep -v UNBIND
[] conn=2 op=0 BIND dn="cn=directory manager" method=128 version=3
[] conn=3 op=0 BIND dn="cn=directory manager" method=128 version=3
[] conn=4 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=5 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=6 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=7 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=8 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=9 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=10 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=11 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=12 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=14 op=0 BIND dn="uid=troot,o=cbrld.com" method=128 version=3
[] conn=16 op=0 BIND dn="cn=directory manager" method=128 version=3

Since chaining backend manages connections in the connection pool, once it's used without bound, it continues being used.

Interestingly, the connection with no bind occurs when the concurrent connection count reaches maxconnections (20, by default) and woken by receiving the notification from other thread. This case, conn=13 is unbound and closed, and conn=15 is established.

[] conn=13 op=80931 SRCH base="o=farm1,o=cbrLD.com" sc
ope=2 filter="(cn=monsieur47560)" attrs=ALL authzid="uid=buser,o=cbrld.com"
[] conn=13 op=80931 RESULT err=0 tag=101 nentries=0 etime=0
[] conn=13 op=80932 UNBIND
[] conn=13 op=80932 fd=64 closed - U1
[] conn=15 fd=64 slot=64 connection from 10.16.66.124 to 10.16.66.124
[] conn=15 op=0 SRCH base="o=farm1,o=cbrLD.com" scope=2 filter="(cn=monsieur14394)" attrs=ALL authzid="uid=buser,o=cbrld.com"
[] conn=15 op=0 RESULT err=0 tag=101 nentries=0 etime=0
    ....

Only a suspicious code which could provide a connection without binding is the case that (pool->bindit == 0). But there is no place where 0 is setting to bindit. It should be always 1. But since we don't use the value we could get rid of the check (line 362) in the future.

158 int
159 cb_get_connection(cb_conn_pool * pool,
160                   LDAP ** lld,
161                   cb_outgoing_conn ** cc,
162                   struct timeval * maxtime,
163                   char **errmsg)
164 {
    ...
339                         ld = slapi_ldap_init(hostname, port, secure, isMultiThread);
    ...
359                         /* no controls and simple bind only */
360                         /* For now, bind even if no user to detect error */
361                         /* earlier                                       */
362                         if (pool->bindit) {
    ...
397                                 /* Password-based client authentication */
398                                 rc = slapi_ldap_bind(ld, binddn, plain, mech    , NULL, &serverctrls,
399                                                      &bind_to, NULL);
400
401                                 if ( ret == 0 ) slapi_ch_free_string(&plain)    ; /* free plain only if it has been duplicated */
    ...

Retested by Viktor and the test passed successfully.
Closing this bug.

Metadata Update from @nhosoi:
- Issue assigned to nhosoi
- Issue set to the milestone: 1.3.6 backlog

5 years ago

389-ds-base is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in 389-ds-base's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/389ds/389-ds-base/issues/559

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Metadata Update from @spichugi:
- Issue close_status updated to: wontfix (was: Fixed)

2 years ago

Login to comment on this ticket.

Metadata