Hi,
I have setup an LDAP proxy using OpenLDAP 2.4.23 running on CentOS release 6.2 Linux 2.6.32-220.4.2.el6.x86_64. Every second search operation on a connection returns an error:
SEARCH RESULT tag=101 err=1 nentries=0 text=000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
database ldap readonly on suffix "dc=example,dc=com" # Recreate cached connection before it can be dropped by the Active Directory. Default Active Directory timeout MaxConnIdleTime=900 idle-timeout 899 rebind-as-user yes uri "ldap://169.254.253.228/ ldap://169.254.239.115/ ldap://169.254.245.81/ ldap://169.254.239.91/"
Here is an extract of the LDAP log, filtered on one connection:
Jan 22 16:41:17 vmldapproxy1 slapd[1851]: conn=1035 fd=29 ACCEPT from IP=172.16.10.126:3579 (IP=0.0.0.0:389) Jan 22 16:41:17 vmldapproxy1 slapd[1851]: conn=1035 op=0 BIND dn="cn=sa_srv,ou=service accounts,dc=example,dc=com" method=128 Jan 22 16:41:17 vmldapproxy1 slapd[1851]: conn=1035 op=0 BIND dn="cn=sa_srv,ou=service accounts,dc=example,dc=com" mech=SIMPLE ssf=0 Jan 22 16:41:17 vmldapproxy1 slapd[1851]: conn=1035 op=0 RESULT tag=97 err=0 text= Jan 22 17:21:46 vmldapproxy1 slapd[1851]: conn=1035 op=1 SRCH base="dc=example,dc=com" scope=2 deref=3 filter="(|(cn=foobar)(uid=foobar)(sn=foobar)(givenName=foobar)(mail=foobar))" Jan 22 17:21:46 vmldapproxy1 slapd[1851]: conn=1035 op=1 SRCH attr=FullName userPassword MailServer mail CalendarDomain MailFile uid ServerName EncryptIncomingMail ListName MailSystem objectClass member NetUserName SametimeServer uniqueMember DB2UserName MailDomain NotesDN AltFullName HTTPPasswordChangeDate modifyTimestamp Location CertificateThumbprint MailAddress HTTPPasswordForceChange Policy MessageStorage NewMailFile LTPA-UsrNm NewMailServer AltFullNameLanguage CN Jan 22 17:21:46 vmldapproxy1 slapd[1851]: conn=1035 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= Jan 22 17:23:31 vmldapproxy1 slapd[1851]: conn=1035 op=2 SRCH base="dc=example,dc=com" scope=2 deref=3 filter="(|(cn=foo.bar@example.com)(uid=foo.bar@example.com)(sn=foo.bar@example.com)(givenName=foo.bar@example.com)(mail=foo.bar@example.com))" Jan 22 17:23:31 vmldapproxy1 slapd[1851]: conn=1035 op=2 SRCH attr=FullName userPassword MailServer mail CalendarDomain MailFile uid ServerName EncryptIncomingMail ListName MailSystem objectClass member NetUserName SametimeServer uniqueMember DB2UserName MailDomain NotesDN AltFullName HTTPPasswordChangeDate modifyTimestamp Location CertificateThumbprint MailAddress HTTPPasswordForceChange Policy MessageStorage NewMailFile LTPA-UsrNm NewMailServer AltFullNameLanguage CN Jan 22 17:23:31 vmldapproxy1 slapd[1851]: conn=1035 op=2 SEARCH RESULT tag=101 err=1 nentries=0 text=000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
Every subsequent search operation going forward generates the same error.
The time difference between the bind (op=0) and the first successful search (op=1) is 40 minutes 29 seconds. The time between op=1 and the first failed search op=2 is 1 minute 45 seconds. This behaviour is consistent for all connections, and appears independent of time. Therefore I'm not seeing how timeouts factor into this issue.
Appears a few folks have posted about this, here and elsewhere, but I could not find any suitable explanation that resolved the issue. Hoping someone can help me out.
Thanks, and regards, Bryce Powell
--On Wednesday, January 23, 2013 9:24 AM -0700 Bryce Powell Bryce.Powell@telus.com wrote:
Hi,
I have setup an LDAP proxy using OpenLDAP 2.4.23 running on CentOS release 6.2 Linux 2.6.32-220.4.2.el6.x86_64. Every second search operation on a connection returns an error:
Why are you using 2.4.23? Upgrade to a current release. If you are not able to build OpenLDAP yourself, try the packages at http://ltb-project.org/wiki/download#openldap
--Quanah
--
Quanah Gibson-Mount Sr. Member of Technical Staff Zimbra, Inc A Division of VMware, Inc. -------------------- Zimbra :: the leader in open source messaging and collaboration
On Wed, Jan 23, 2013 at 09:24:59AM -0700, Bryce Powell wrote:
I have setup an LDAP proxy using OpenLDAP 2.4.23 running on CentOS release 6.2 Linux 2.6.32-220.4.2.el6.x86_64. Every second search operation on a connection returns an error:
SEARCH RESULT tag=101 err=1 nentries=0 text=000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
You later say:
Every subsequent search operation going forward generates the same error.
which is not quite the same.
In any case, the error you quote obviously comes from the remote (AD) server so you should focus your investigation on the link from the OpenLDAP proxy to AD.
database ldap readonly on suffix "dc=example,dc=com" # Recreate cached connection before it can be dropped by the Active Directory. Default Active Directory timeout MaxConnIdleTime=900 idle-timeout 899 rebind-as-user yes uri "ldap://169.254.253.228/ ldap://169.254.239.115/ ldap:/ /169.254.245.81/ ldap://169.254.239.91/"
I would suggest simplifying the setup to start with - cut it down to a single back-end uri and see what happens. If that works properly, then try with each of those URIs in turn in case one of the remote servers is set up differently.
You should consider using tcpdump and/or wireshark to watch the traffic from the proxy to the remote AD servers. That will tell you what is really happenning on the backend links.
As an aside, I would not set the idle-timeout so close to the value that the remote server uses. It only needs a tiny clock skew for the behaviour to change completely. You should also look for firewalls (both in the network and on the servers) and find out what they do with idle connections: it is usually seriously damaging to this sort of setup.
Andrew
On Wed, Jan 23, 2013 at 09:24:59AM -0700, Bryce Powell wrote:
I have setup an LDAP proxy using OpenLDAP 2.4.23 running on CentOS release 6.2 Linux 2.6.32-220.4.2.el6.x86_64. Every second search operation on a connection returns an error:
SEARCH RESULT tag=101 err=1 nentries=0 text=000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
You later say:
Every subsequent search operation going forward generates the same
error.
which is not quite the same.
Agreed - that was badly worded. Every subsequent search operation, *on that same connection*, going forward generates the same error.
In any case, the error you quote obviously comes from the remote (AD) server so you should focus your investigation on the link from the OpenLDAP proxy to AD.
database ldap readonly on suffix "dc=example,dc=com" # Recreate cached connection before it can be dropped by the Active
Directory.
Default Active Directory timeout MaxConnIdleTime=900 idle-timeout 899 rebind-as-user yes uri "ldap://169.254.253.228/ ldap://169.254.239.115/ ldap:/ /169.254.245.81/ ldap://169.254.239.91/"
I would suggest simplifying the setup to start with - cut it down to a single back-end uri and see what happens. If that works properly, then try with each of those URIs in turn in case one of the remote servers is set up differently.
You should consider using tcpdump and/or wireshark to watch the traffic from the proxy to the remote AD servers. That will tell you what is really happenning on the backend links.
As an aside, I would not set the idle-timeout so close to the value that the remote server uses. It only needs a tiny clock skew for the behaviour to change completely. You should also look for firewalls (both in the network and on the servers) and find out what they do with idle connections: it is usually seriously damaging to this sort of setup.
Andrew
The firewall timeouts are way longer, but good point about the idle-timeout being so close to the AD timeout. Thanks for your input, and I'll post further findings as I progress with the troubleshooting.
--Bryce
--
| From Andrew Findlay, Skills 1st Ltd | | Consultant in large-scale systems, networks, and directory services | | http://www.skills-1st.co.uk/ +44 1628 782565 |
-----Original Message----- From: Bryce Powell Sent: January 24, 2013 08:18 AM To: 'Andrew Findlay' Cc: openldap-technical@openldap.org Subject: RE: slapd-ldap: second search operation always generates error LdapErr: DSID-0C0906E8
On Wed, Jan 23, 2013 at 09:24:59AM -0700, Bryce Powell wrote:
I have setup an LDAP proxy using OpenLDAP 2.4.23 running on CentOS release 6.2 Linux 2.6.32-220.4.2.el6.x86_64. Every second search operation on a connection returns an error:
SEARCH RESULT tag=101 err=1 nentries=0 text=000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
You later say:
Every subsequent search operation going forward generates the same
error.
which is not quite the same.
Agreed - that was badly worded. Every subsequent search operation, *on that same connection*, going forward generates the same error.
In any case, the error you quote obviously comes from the remote (AD) server so you should focus your investigation on the link from the
OpenLDAP
proxy to AD.
database ldap readonly on suffix "dc=example,dc=com" # Recreate cached connection before it can be dropped by the Active
Directory.
Default Active Directory timeout MaxConnIdleTime=900 idle-timeout 899 rebind-as-user yes uri "ldap://169.254.253.228/ ldap://169.254.239.115/ ldap:/ /169.254.245.81/ ldap://169.254.239.91/"
I would suggest simplifying the setup to start with - cut it down to a single back-end uri and see what happens. If that works properly, then try with each of those URIs in turn in case one of the remote servers is set up differently.
You should consider using tcpdump and/or wireshark to watch the traffic from the proxy to the remote AD servers. That will tell you what is really happenning on the backend links.
As an aside, I would not set the idle-timeout so close to the value that the remote server uses. It only needs a tiny clock skew for the behaviour to change completely. You should also look for firewalls (both in the network and on the servers) and find out what they do with idle connections: it is usually seriously damaging to this sort of setup.
Andrew
The firewall timeouts are way longer, but good point about the idle-timeout being so close to the AD timeout. Thanks for your input, and I'll post further findings as I progress with the troubleshooting.
I tested various intervals for the idle-timeout directive, and the shorter the interval, the earlier the LdapErr: DSID-0C0906E8 error occurred. I also tried replacing it with the conn-ttl directive, but this also exhibited the same behaviour. There is a firewall between the LDAP proxy and the remote AD's, and the settings are as follows: * timeout conn= 12:00:00 * half-closed = 0:10:00
I went down to idle-timeout of 60 seconds, and then the LdapErr: DSID-0C0906E8 error would occur about 3 to 5 minutes after a slapd restart, under 'normal' user load.
I tend to think that there is indeed an issue with the idle-timeout functionality under the version of OpenLDAP we are using. Hopefully a more recent release has addressed this.
--Bryce
--
| From Andrew Findlay, Skills 1st Ltd | | Consultant in large-scale systems, networks, and directory services | | http://www.skills-1st.co.uk/ +44 1628 782565 |
openldap-technical@openldap.org
-
Andrew Findlay -
Bryce Powell -
Quanah Gibson-Mount