LDAP traffic chaos / duplicate authentications

Server
, , ,
1

After upgrading OC Server, a previously working LDAP setup is broken; LDAP is now making at least three authentication calls each time a client logs in through webinterface, and frequent unwanted authentications from the desktop client (previously it was only one authenticaiton when the client booted up).
(NB This matters because I've successfully implemented 2-factor authentication onto the LDAP server, so too many authentications causes total chaos)
My question is whether the LDAP coding in OC has changed; and is there way to prevent these multiple authentications?
I've noted topic: https://central.owncloud.org/t/lot-of-ldap-traffic/1909 which may have similar cause.

Steps to reproduce
1. install OC server & an LDAP server (e.g. OpenLDAP)
2. login to OC server as a user via web interface
3. check log of LDAP server to see multiple bindings for single login. (Not sure how to see that on OC's own log)

Expected behaviour
OC should perform a single authentication on LOGIN, and thereafter cache shoudl prevent further authentications being necessary; the OC desktop client should authenticate only once at startup.
THIS WAS PREVIOUSLY WORKING FINE

Actual behaviour
The LDAP server is being called at least three times on php/web login.
See copy below pasted of LDAP log for just a single log in of a test account via web (PHPP interface.

Server configuration
Operating system: Ubuntu
Web server: Apache/2.4.7 (Ubuntu)
Database: MySQL
PHP version: PHP 5.5.9-1ubuntu4.19 (cli) (built: Jul 28 2016 19:31:33)
ownCloud version (see ownCloud admin page): ownCloud 9.1.0 (stable)
Updated from an older ownCloud or fresh install: updated
ownCloud log (data/owncloud.log, see https://central.owncloud.org/t/how-to-find-webserver-or-oc-logfile-enable-php-logfile/808):

Special configuration (external storage, external authentication, reverse proxy, server-side-encryption):

Integrity status for oC9+

Login as admin user into your ownCloud and access
http://example.com/index.php/settings/integrity/failed
paste the results here.
No errors have been found.

COPY OF LDAP LOG

:40 slapd[1098]: conn=1215 fd=19 ACCEPT from IP=127.0.0.1:41620 (IP=0.0.0.0:389)
:40 slapd[1098]: conn=1215 op=0 BIND dn="uid=user**********" method=128
:40 slapd[1098]: conn=1215 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:40 slapd[1098]: conn=1215 op=0 RESULT tag=97 err=0 text=
:40 slapd[1098]: conn=1215 op=1 SRCH base="dc=so**********" scope=2 deref=0 filter="(&(|(objectClass=inetOrgPerson))(|(uid=ttest)(|(?mailPrimaryAddress=ttest)(mail=ttest))))"
:40 slapd[1098]: conn=1215 op=1 SRCH attr=dn uid samaccountname memberof 1.1 mail cn 1.1 jpegphoto thumbnailphoto
:40 slapd[1098]: <= bdb_equality_candidates: (uid) not indexed
:40 slapd[1098]: <= bdb_equality_candidates: (mail) not indexed
:40 slapd[1098]: conn=1215 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:40 slapd[1098]: conn=1216 fd=21 ACCEPT from IP=127.0.0.1:41621 (IP=0.0.0.0:389)
:40 slapd[1098]: conn=1216 op=0 BIND dn="cn=tes******,ou=users,dc=so**********" method=128
:40 slapd[1098]: conn=1216 op=0 RESULT tag=97 err=49 text=
:40 slapd[1098]: conn=1216 op=1 UNBIND
:40 slapd[1098]: conn=1216 fd=21 closed
:40 slapd[1098]: conn=1215 op=2 UNBIND
:40 slapd[1098]: conn=1215 fd=19 closed
:43 slapd[1098]: conn=1217 fd=19 ACCEPT from IP=127.0.0.1:41622 (IP=0.0.0.0:389)
:43 slapd[1098]: conn=1217 op=0 BIND dn="uid=user**********" method=128
:43 slapd[1098]: conn=1217 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:43 slapd[1098]: conn=1217 op=0 RESULT tag=97 err=0 text=
:43 slapd[1098]: conn=1217 op=1 SRCH base="dc=so**********" scope=2 deref=0 filter="(&(|(objectClass=inetOrgPerson))(|(uid=ttest)(|(?mailPrimaryAddress=ttest)(mail=ttest))))"
:43 slapd[1098]: conn=1217 op=1 SRCH attr=dn uid samaccountname memberof 1.1 mail cn 1.1 jpegphoto thumbnailphoto
:43 slapd[1098]: <= bdb_equality_candidates: (uid) not indexed
:43 slapd[1098]: <= bdb_equality_candidates: (mail) not indexed
:43 slapd[1098]: conn=1217 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:43 slapd[1098]: conn=1218 fd=21 ACCEPT from IP=127.0.0.1:41623 (IP=0.0.0.0:389)
:43 slapd[1098]: conn=1218 op=0 BIND dn="cn=tes******,ou=users,dc=so**********" method=128
:43 slapd[1098]: conn=1218 op=0 BIND dn="cn=tes******,ou=users,dc=so**********" mech=SIMPLE ssf=0
:43 slapd[1098]: conn=1218 op=0 RESULT tag=97 err=0 text=
:43 slapd[1098]: conn=1218 op=1 UNBIND
:43 slapd[1098]: conn=1218 fd=21 closed
:43 slapd[1098]: conn=1217 op=2 SRCH base="dc=so**********" scope=2 deref=0 filter="(&(|(objectClass=inetOrgPerson))(|(uid=ttest)(|(?mailPrimaryAddress=ttest)(mail=ttest))))"
:43 slapd[1098]: conn=1217 op=2 SRCH attr=dn uid samaccountname memberof 1.1 mail cn 1.1 jpegphoto thumbnailphoto
:43 slapd[1098]: <= bdb_equality_candidates: (uid) not indexed
:43 slapd[1098]: <= bdb_equality_candidates: (mail) not indexed
:43 slapd[1098]: conn=1217 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:43 slapd[1098]: conn=1219 fd=21 ACCEPT from IP=127.0.0.1:41624 (IP=0.0.0.0:389)
:43 slapd[1098]: conn=1219 op=0 BIND dn="cn=tes******,ou=users,dc=so**********" method=128
:43 slapd[1098]: conn=1219 op=0 BIND dn="cn=tes******,ou=users,dc=so**********" mech=SIMPLE ssf=0
:43 slapd[1098]: conn=1219 op=0 RESULT tag=97 err=0 text=
:43 slapd[1098]: conn=1219 op=1 UNBIND
:43 slapd[1098]: conn=1219 fd=21 closed
:43 slapd[1098]: conn=1217 op=3 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:43 slapd[1098]: conn=1217 op=3 SRCH attr=1.1
:43 slapd[1098]: conn=1217 op=3 SEARCH RESULT tag=101 err=0 nentries=1 text=
:43 slapd[1098]: conn=1217 op=4 UNBIND
:43 slapd[1098]: conn=1217 fd=19 closed
:43 slapd[1098]: conn=1220 fd=19 ACCEPT from IP=127.0.0.1:41625 (IP=0.0.0.0:389)
:43 slapd[1098]: conn=1220 op=0 BIND dn="uid=user**********" method=128
:43 slapd[1098]: conn=1220 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:43 slapd[1098]: conn=1220 op=0 RESULT tag=97 err=0 text=
:43 slapd[1098]: conn=1220 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:43 slapd[1098]: conn=1220 op=1 SRCH attr=1.1
:43 slapd[1098]: conn=1220 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:43 slapd[1098]: conn=1220 op=2 SRCH base="dc=so**********" scope=2 deref=0 filter="(&(|(objectClass=inetOrgPerson))(|(uid=ttest)(|(?mailPrimaryAddress=ttest)(mail=ttest))))"
:43 slapd[1098]: conn=1220 op=2 SRCH attr=dn uid samaccountname memberof 1.1 mail cn 1.1 jpegphoto thumbnailphoto
:43 slapd[1098]: <= bdb_equality_candidates: (uid) not indexed
:43 slapd[1098]: <= bdb_equality_candidates: (mail) not indexed
:43 slapd[1098]: conn=1220 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:43 slapd[1098]: conn=1221 fd=21 ACCEPT from IP=127.0.0.1:41626 (IP=0.0.0.0:389)
:43 slapd[1098]: conn=1221 op=0 BIND dn="cn=tes******,ou=users,dc=so**********" method=128
:43 slapd[1098]: conn=1221 op=0 BIND dn="cn=tes******,ou=users,dc=so**********" mech=SIMPLE ssf=0
:43 slapd[1098]: conn=1221 op=0 RESULT tag=97 err=0 text=
:43 slapd[1098]: conn=1221 op=1 UNBIND
:43 slapd[1098]: conn=1221 fd=21 closed
:43 slapd[1098]: conn=1220 op=3 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:43 slapd[1098]: conn=1220 op=3 SRCH attr=1.1
:43 slapd[1098]: conn=1220 op=3 SEARCH RESULT tag=101 err=0 nentries=1 text=
:44 slapd[1098]: conn=1220 op=4 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:44 slapd[1098]: conn=1220 op=4 SRCH attr=1.1
:44 slapd[1098]: conn=1220 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
:44 slapd[1098]: conn=1220 op=5 SRCH base="cn=tes*****,ou=users,dc=so**********" scope=0 deref=0 filter="(objectClass=)"
:44 slapd[1098]: conn=1220 op=5 SRCH attr=cn
:44 slapd[1098]: conn=1220 op=5 SEARCH RESULT tag=101 err=0 nentries=1 text=
:44 slapd[1098]: conn=1220 op=6 UNBIND
:44 slapd[1098]: conn=1220 fd=19 closed
:44 slapd[1098]: conn=1222 fd=19 ACCEPT from IP=127.0.0.1:41627 (IP=0.0.0.0:389)
:44 slapd[1098]: conn=1222 op=0 BIND dn="uid=user**********" method=128
:44 slapd[1098]: conn=1222 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:44 slapd[1098]: conn=1222 op=0 RESULT tag=97 err=0 text=
:44 slapd[1098]: conn=1222 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:44 slapd[1098]: conn=1222 op=1 SRCH attr=1.1
:44 slapd[1098]: conn=1222 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:44 slapd[1098]: conn=1222 op=2 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:44 slapd[1098]: conn=1222 op=2 SRCH attr=1.1
:44 slapd[1098]: conn=1222 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:44 slapd[1098]: conn=1222 op=3 UNBIND
:44 slapd[1098]: conn=1222 fd=19 closed
:44 slapd[1098]: conn=1223 fd=19 ACCEPT from IP=127.0.0.1:41628 (IP=0.0.0.0:389)
:44 slapd[1098]: conn=1223 op=0 BIND dn="uid=user**********" method=128
:44 slapd[1098]: conn=1223 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:44 slapd[1098]: conn=1223 op=0 RESULT tag=97 err=0 text=
:44 slapd[1098]: conn=1223 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:44 slapd[1098]: conn=1223 op=1 SRCH attr=1.1
:44 slapd[1098]: conn=1223 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:44 slapd[1098]: conn=1223 op=2 UNBIND
:44 slapd[1098]: conn=1223 fd=19 closed
:45 slapd[1098]: conn=1224 fd=19 ACCEPT from IP=127.0.0.1:41629 (IP=0.0.0.0:389)
:45 slapd[1098]: conn=1224 op=0 BIND dn="uid=user**********" method=128
:45 slapd[1098]: conn=1224 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:45 slapd[1098]: conn=1224 op=0 RESULT tag=97 err=0 text=
:45 slapd[1098]: conn=1224 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1224 op=1 SRCH attr=1.1
:45 slapd[1098]: conn=1224 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1224 op=2 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1224 op=2 SRCH attr=1.1
:45 slapd[1098]: conn=1224 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1224 op=3 UNBIND
:45 slapd[1098]: conn=1224 fd=19 closed
:45 slapd[1098]: conn=1225 fd=19 ACCEPT from IP=127.0.0.1:41630 (IP=0.0.0.0:389)
:45 slapd[1098]: conn=1225 op=0 BIND dn="uid=user**********" method=128
:45 slapd[1098]: conn=1225 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:45 slapd[1098]: conn=1225 op=0 RESULT tag=97 err=0 text=
:45 slapd[1098]: conn=1225 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1225 op=1 SRCH attr=1.1
:45 slapd[1098]: conn=1225 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1225 op=2 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1225 op=2 SRCH attr=1.1
:45 slapd[1098]: conn=1225 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1225 op=3 UNBIND
:45 slapd[1098]: conn=1225 fd=19 closed
:45 slapd[1098]: conn=1226 fd=19 ACCEPT from IP=127.0.0.1:41631 (IP=0.0.0.0:389)
:45 slapd[1098]: conn=1226 op=0 BIND dn="uid=user**********" method=128
:45 slapd[1098]: conn=1226 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:45 slapd[1098]: conn=1226 op=0 RESULT tag=97 err=0 text=
:45 slapd[1098]: conn=1226 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1226 op=1 SRCH attr=1.1
:45 slapd[1098]: conn=1226 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1226 op=2 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1226 op=2 SRCH attr=1.1
:45 slapd[1098]: conn=1226 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1226 op=3 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1226 op=3 SRCH attr=1.1
:45 slapd[1098]: conn=1226 op=3 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1226 op=4 SRCH base="cn=tes*****,ou=users,dc=so**********" scope=0 deref=0 filter="(objectClass=)"
:45 slapd[1098]: conn=1226 op=4 SRCH attr=cn
:45 slapd[1098]: conn=1226 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1226 op=5 UNBIND
:45 slapd[1098]: conn=1226 fd=19 closed
:45 slapd[1098]: conn=1227 fd=19 ACCEPT from IP=127.0.0.1:41632 (IP=0.0.0.0:389)
:45 slapd[1098]: conn=1227 op=0 BIND dn="uid=user**********" method=128
:45 slapd[1098]: conn=1227 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:45 slapd[1098]: conn=1227 op=0 RESULT tag=97 err=0 text=
:45 slapd[1098]: conn=1227 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1227 op=1 SRCH attr=1.1
:45 slapd[1098]: conn=1227 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1227 op=2 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1227 op=2 SRCH attr=1.1
:45 slapd[1098]: conn=1227 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1227 op=3 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1227 op=3 SRCH attr=1.1
:45 slapd[1098]: conn=1227 op=3 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1227 op=4 SRCH base="cn=tes*****,ou=users,dc=so**********" scope=0 deref=0 filter="(objectClass=)"
:45 slapd[1098]: conn=1227 op=4 SRCH attr=cn
:45 slapd[1098]: conn=1227 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1227 op=5 UNBIND
:45 slapd[1098]: conn=1227 fd=19 closed
:45 slapd[1098]: conn=1228 fd=19 ACCEPT from IP=127.0.0.1:41633 (IP=0.0.0.0:389)
:45 slapd[1098]: conn=1228 op=0 BIND dn="uid=user**********" method=128
:45 slapd[1098]: conn=1228 op=0 BIND dn="uid=user**********" mech=SIMPLE ssf=0
:45 slapd[1098]: conn=1228 op=0 RESULT tag=97 err=0 text=
:45 slapd[1098]: conn=1228 op=1 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1228 op=1 SRCH attr=1.1
:45 slapd[1098]: conn=1228 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1228 op=2 SRCH base="cn=tes******,ou=users,dc=so**********" scope=0 deref=0 filter="(|(objectClass=inetOrgPerson))"
:45 slapd[1098]: conn=1228 op=2 SRCH attr=1.1
:45 slapd[1098]: conn=1228 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
:45 slapd[1098]: conn=1228 op=3 UNBIND
:45 slapd[1098]: conn=1228 fd=19 closed

2

Hi,

if something like this is happening after an upgrade then please report it directly to:

https://github.com/owncloud/core/issues

Developers are not yet that active in here so such issues are most likely getting lost in this forums.

3

Thanks - i will do that

4

Thanks. Here the report reference:

5

Hello - I've updated and simplified the issue on Github... grateful if you could flag this to anyone who knows about the LDAP code as not getting any response at all and this has broken a system! Thanks.

6

Sorry, have no idea who this could be. Just have patience or revert to your backup until some one is having a look at the issue.