online(a)mark.ziesemer.com wrote:
Full_Name: Mark A. Ziesemer
Version: 2.4.21
OS: Ubuntu Linux 10.04
URL:
ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (2001:470:1f11:3ae:4d6d:3d3e:faa6:ee3d)
Many "connection_read(): no connection!" warnings are written to
/var/log/debug
and /var/log/syslog by slapd. As stated at
http://www.openldap.org/lists/openldap-software/200811/msg00079.html , this is
apparently not a problem with slapd, but a client that is disconnecting without
first unbinding.
This also happens when the connection manager queues up a thread to handle a
"socket is readable" event on a socket that's in the process of closing.
Pretty much unavoidable, when a lot of threads are active. I don't see this as
a high enough priority to warrant fixing.
This appears to be an issue with the libldap client library provided
by OpenLDAP
itself (2.4.21), and not the slapd daemon.
Issue is reproducible even by just using "ldapsearch -H ldapi:///", but only
if
a bind DN is specified (-D) and external authentication is not used.
Running slapd with logging enabled (-d 8) shows the following 3 sequences -
ldapsearch command followed by the slapd logs. Note that the
"connection_read(): no connection!" is only visible on the middle pair.
$ ldapsearch -LLL -Y EXTERNAL -H ldapi:/// -b ""
SASL/EXTERNAL authentication started
SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
SASL SSF: 0
No such object (32)
slap_listener_activate(9):
>>> slap_listener(ldapi:///)
connection_get(14): got connid=1000
connection_read(14): checking for input on id=1000
ber_get_next
ber_get_next: tag 0x30 len 24 contents:
op tag 0x60, time 1273546410
ber_get_next
conn=1000 op=0 do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt ({m) ber:
ber_scanf fmt (m) ber:
ber_scanf fmt (}}) ber:
>>> dnPrettyNormal:<>
<<< dnPrettyNormal:<>,<>
do_bind: dn () SASL mech EXTERNAL
==>slap_sasl2dn: converting SASL name
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth to a DN
<==slap_sasl2dn: Converted SASL name to<nothing>
SASL Authorize [conn=1000]: proxy authorization allowed authzDN=""
send_ldap_sasl: err=0 len=-1
do_bind: SASL/EXTERNAL bind:
dn="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth" sasl_ssf=0
send_ldap_response: msgid=1 tag=97 err=0
ber_flush2: 14 bytes to sd 14
<== slap_sasl_bind: rc=0
connection_get(14): got connid=1000
connection_read(14): checking for input on id=1000
ber_get_next
ber_get_next: tag 0x30 len 37 contents:
op tag 0x63, time 1273546410
ber_get_next
conn=1000 op=1 do_search
ber_scanf fmt ({miiiib) ber:
>>> dnPrettyNormal:<>
<<< dnPrettyNormal:<>,<>
ber_scanf fmt (m) ber:
ber_scanf fmt ({M}}) ber:
send_ldap_result: conn=1000 op=1 p=3
send_ldap_response: msgid=2 tag=101 err=32
ber_flush2: 14 bytes to sd 14
connection_get(14): got connid=1000
connection_read(14): checking for input on id=1000
ber_get_next
ber_get_next: tag 0x30 len 5 contents:
op tag 0x42, time 1273546410
ber_get_next
conn=1000 op=2 do_unbind
connection_close: conn=1000 sd=14
$ ldapsearch -H ldapi:/// -D "cn=admin,dc=example,dc=com" -b "" -W
Enter LDAP Password:
ldap_bind: Invalid credentials (49)
slap_listener_activate(9):
>>> slap_listener(ldapi:///)
connection_get(14): got connid=1001
connection_read(14): checking for input on id=1001
ber_get_next
ber_get_next: tag 0x30 len 44 contents:
op tag 0x60, time 1273546420
ber_get_next
conn=1001 op=0 do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt (m}) ber:
>>> dnPrettyNormal:<cn=admin,dc=example,dc=com>
<<<
dnPrettyNormal:<cn=admin,dc=example,dc=com>,<cn=admin,dc=example,dc=com>
do_bind: version=3 dn="cn=admin,dc=example,dc=com" method=128
send_ldap_result: conn=1001 op=0 p=3
send_ldap_response: msgid=1 tag=97 err=49
ber_flush2: 14 bytes to sd 14
connection_get(14): got connid=1001
connection_read(14): checking for input on id=1001
ber_get_next
ber_get_next on fd 14 failed errno=0 (Success)
connection_close: conn=1001 sd=14
connection_read(14): no connection!
connection_read(14): no connection!
$ ldapsearch -H ldap:/// -D "cn=admin,dc=example,dc=com" -b "" -W
Enter LDAP Password:
ldap_bind: Invalid credentials (49)
slap_listener_activate(8):
>>> slap_listener(ldap:///)
connection_get(14): got connid=1002
connection_read(14): checking for input on id=1002
ber_get_next
ber_get_next: tag 0x30 len 44 contents:
op tag 0x60, time 1273546425
ber_get_next
conn=1002 op=0 do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt (m}) ber:
>>> dnPrettyNormal:<cn=admin,dc=example,dc=com>
<<<
dnPrettyNormal:<cn=admin,dc=example,dc=com>,<cn=admin,dc=example,dc=com>
do_bind: version=3 dn="cn=admin,dc=example,dc=com" method=128
send_ldap_result: conn=1002 op=0 p=3
send_ldap_response: msgid=1 tag=97 err=49
ber_flush2: 14 bytes to sd 14
connection_get(14): got connid=1002
connection_read(14): checking for input on id=1002
ber_get_next
ber_get_next on fd 14 failed errno=0 (Success)
connection_close: conn=1002 sd=14
--
-- Howard Chu
CTO, Symas Corp.
http://www.symas.com
Director, Highland Sun
http://highlandsun.com/hyc/
Chief Architect, OpenLDAP
http://www.openldap.org/project/