(ITS#6577) OL failes to delete valid entries
by quanah@zimbra.com
Full_Name: Quanah Gibson-Mount
Version: RE24
OS: Linux 2.6
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (75.111.45.108)
When running test008 in a loop, it will occasionally fail. Investigation shows
that it fails to delete an entry known to exist in the database:
Here we can see a search that finds the entry:
conn=1028 op=433 SRCH base="dc=example,dc=com" scope=2 deref=0
filter="(cn=james*)"
conn=1028 op=433 SRCH attr=cn sn
=> hdb_search
bdb_dn2entry("dc=example,dc=com")
search_candidates: base="dc=example,dc=com" (0x00000001) scope=2
=> hdb_dn2idl("dc=example,dc=com")
=> bdb_equality_candidates (objectClass)
=> key_read
bdb_idl_fetch_key: [b49d1940]
<= bdb_index_read: failed (-30988)
<= bdb_equality_candidates: id=0, first=0, last=0
=> bdb_substring_candidates (cn)
=> key_read
bdb_idl_fetch_key: [0d554a2b]
<= bdb_index_read 4 candidates
<= bdb_substring_candidates: 4, first=12, last=148
bdb_search_candidates: id=4 first=12 last=148
=> send_search_entry: conn 1028 dn="cn=James A Jones 1,ou=Alumni
Association,ou=People,dc=example,dc=com"
ber_flush2: 146 bytes to sd 34
<= send_search_entry: conn 1028 exit.
=> send_search_entry: conn 1028 dn="cn=James A Jones 2,ou=Information Technology
Division,ou=People,dc=example,dc=com"
ber_flush2: 157 bytes to sd 34
<= send_search_entry: conn 1028 exit.
=> send_search_entry: conn 1028 dn="cn=James A Jones 2,ou=Alumni
Association,ou=People,dc=example,dc=com"
ber_flush2: 146 bytes to sd 34
<= send_search_entry: conn 1028 exit.
=> send_search_entry: conn 1028 dn="cn=James A Jones
4,ou=People,dc=example,dc=com"
ber_flush2: 122 bytes to sd 34
<= send_search_entry: conn 1028 exit.
A few lines further, this entry is deleted:
=> send_search_entry: conn 1049 dn="cn=James A Jones 1,ou=Alumni
Association,ou=People,dc=example,dc=com"
ber_flush2: 47 bytes to sd 29
ber_flush2: 146 bytes to sd 32
<= send_search_entry: conn 1056 exit.
send_ldap_result: conn=1056 op=289 p=3
send_ldap_result: err=0 matched="" text=""
send_ldap_response: msgid=290 tag=101 err=0
ber_flush2: 15 bytes to sd 29
conn=1056 op=289 SEARCH RESULT tag=101 err=0 nentries=1 text=
bdb_dn2entry("cn=james a jones 4,ou=people,dc=example,dc=com")
<=- hdb_delete: no such object cn=James A Jones 4,ou=People,dc=example,dc=com
send_ldap_result: conn=1002 op=44 p=3
send_ldap_result: err=10 matched="ou=People,dc=example,dc=com" text=""
send_ldap_response: msgid=45 tag=107 err=32
ber_flush2: 41 bytes to sd 14
The resulting diff show the entry still exists in the generated database:
[root@build01 tests]# diff -u testrun/ldapsearch.flt testrun/ldif.flt
--- testrun/ldapsearch.flt 2010-06-17 16:12:41.000000000 -0700
+++ testrun/ldif.flt 2010-06-17 16:12:41.000000000 -0700
@@ -308,25 +308,6 @@
facsimileTelephoneNumber: +1 313 555 8688
telephoneNumber: +1 313 555 7334
-dn: cn=James A Jones 4,ou=People,dc=example,dc=com
-objectClass: OpenLDAPperson
-cn: James A Jones 4
-cn: James Jones
-cn: Jim Jones
-sn: Jones
-uid: jaj
-postalAddress: Alumni Association $ 111 Maple St $ Anytown, MI 48109
-seeAlso: cn=All Staff,ou=Groups,dc=example,dc=com
-userPassword:: OiBhbUZx
-homePostalAddress: 3882 Beverly Rd. $ Anytown, MI 48105
-homePhone: +1 313 555 4772
-description: Outstanding
-title: Mad Cow Researcher, UM Alumni Association
-pager: +1 313 555 3923
-mail: jaj(a)mail.alumni.example.com
-facsimileTelephoneNumber: +1 313 555 4332
-telephoneNumber: +1 313 555 0895
-
dn: cn=Jane Doe,ou=Alumni Association,ou=People,dc=example,dc=com
objectClass: OpenLDAPperson
cn: Jane Doe
13 years, 3 months
Re: (ITS#6572) slapd crash caused by refint's cn=config modification
by mbackes@symas.com
--Apple-Mail-174--9407050
Content-Transfer-Encoding: quoted-printable
Content-Type: text/plain;
charset=us-ascii
Hello, Daniel and Quanah.
> I've tested your patch against HEAD and there seems to be a bug left =
open within (or even newly introduced by?) your patch:
> I've added Quanah into cc as his Call for 2.4.43RE testing seems to =
depend on this ITS.
> *** glibc detected *** /usr/local/openldap/sbin/slaptest: free(): =
invalid pointer: 0x09d507d8 ***
Heh, oops. Extra & in the add case for one of the attributes. Sorry =
for the noise. See attached patch.
Matthew Backes
Symas Corporation
mbackes(a)symas.com
--Apple-Mail-174--9407050
Content-Disposition: attachment;
filename=its-6572-amendment.txt
Content-Type: text/plain;
x-unix-mode=0644;
name="its-6572-amendment.txt"
Content-Transfer-Encoding: 7bit
Index: refint.c
===================================================================
RCS file: /repo/OpenLDAP/pkg/ldap/servers/slapd/overlays/refint.c,v
retrieving revision 1.19.2.14
diff -u -r1.19.2.14 refint.c
--- refint.c 13 Jun 2010 17:38:37 -0000 1.19.2.14
+++ refint.c 17 Jun 2010 18:04:18 -0000
@@ -263,8 +263,8 @@
break;
case REFINT_MODIFIERSNAME:
if ( !BER_BVISNULL( &c->value_ndn )) {
- ch_free( &dd->refint_dn.bv_val );
- ch_free( &dd->refint_ndn.bv_val );
+ ch_free( dd->refint_dn.bv_val );
+ ch_free( dd->refint_ndn.bv_val );
dd->refint_dn = c->value_dn;
dd->refint_ndn = c->value_ndn;
rc = 0;
--Apple-Mail-174--9407050--
13 years, 3 months
Re: (ITS#6572) slapd crash caused by refint's cn=config modification
by daniel@pluta.biz
Hi Matthew,
I've tested your patch against HEAD and there seems to be a bug left
open within (or even newly introduced by?) your patch:
I've added Quanah into cc as his Call for 2.4.43RE testing seems to
depend on this ITS.
Executive summary: ;-)
======================
*** glibc detected *** /usr/local/openldap/sbin/slaptest: free():
invalid pointer: 0x09d507d8 ***
Technical details: ;-)
======================
If I remove the following refint configuration directive from
cn=config's refint-ldif file:
olcRefintModifiersName:
uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=f
oo,dc=bar
slaptest & slapd both startup fine. If the above statement is contained
in the current configuration it results in an "invalid pointer" crash
during slaptest and also during slapd startup (see below)...
Cheers
Daniel
ldif_read_file: read entry file:
"slapd.d/cn=config/olcDatabase={2}hdb/olcOverlay={4}refint.ldif"
=> str2entry: "dn: olcOverlay={4}refint
objectClass: olcOverlayConfig
objectClass: olcRefintConfig
olcOverlay: {4}refint
olcRefintAttribute: secretary
olcRefintAttribute: manager
olcRefintAttribute: roleOccupant
olcRefintAttribute: member
olcRefintAttribute: memberOf
olcRefintAttribute: owner
olcRefintNothing:
uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=
bar
olcRefintModifiersName:
uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=f
oo,dc=bar
structuralObjectClass: olcRefintConfig
entryUUID: ac810092-0b82-102f-9080-ed6f5f0ebf63
creatorsName: cn=config
createTimestamp: 20100613215924Z
entryCSN: 20100614121813.528580Z#000000#000#000000
modifiersName: cn=ldapmanager,cn=config
modifyTimestamp: 20100614121813Z
"
>>> dnPrettyNormal: <olcOverlay={4}refint>
<<< dnPrettyNormal: <olcOverlay={4}refint>, <olcOverlay={4}refint>
>>> dnPretty:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
<<< dnPretty:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
>>> dnPretty:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
<<< dnPretty:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
>>> dnPretty: <cn=config>
<<< dnPretty: <cn=config>
>>> dnNormalize: <cn=config>
<<< dnNormalize: <cn=config>
>>> dnPretty: <cn=ldapmanager,cn=config>
<<< dnPretty: <cn=ldapmanager,cn=config>
>>> dnNormalize: <cn=ldapmanager,cn=config>
<<< dnNormalize: <cn=ldapmanager,cn=config>
<= str2entry(olcOverlay={4}refint) -> 0x9cd6a04
>>> dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
<<< dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>,
<uid=refintoverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
>>> dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
<<< dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>,
<uid=refintoverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
>>> dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
<<< dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>,
<uid=refintoverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
>>> dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
<<< dnPrettyNormal:
<uid=refintOverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>,
<uid=refintoverlay,ou=users,ou=mgmt,ou=example.com,dc=foo,dc=bar>
*** glibc detected *** /usr/local/openldap/sbin/slaptest: free():
invalid pointer: 0x09d507d8 ***
======= Backtrace: =========
/lib/i686/cmov/libc.so.6(+0x6b321)[0xb735c321]
/lib/i686/cmov/libc.so.6(+0x6cb78)[0xb735db78]
/lib/i686/cmov/libc.so.6(cfree+0xAborted
Matthew Backes schrieb:
> Here's a patch that fixes 6572.
>
> * Switch to use BER_BVISNULL, BER_BVZERO, and ch_free instead
> * Clean up Ozone's "breadcrumbs" while we're at it (unrelated but trivial)
> * Should apply cleanly to RE24 and HEAD
> * Older dyn-config refints (RE22, RE23) likely have the same problem
>
> Matthew Backes
> Symas Corporation
> mbackes(a)symas.com
>
>
13 years, 3 months
(ITS#6574) back-meta does not rebind as user when retrying
by masarati@aero.polimi.it
Full_Name: Pierangelo Masarati
Version: HEAD/re24
OS: irrelevant
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (129.72.141.2)
Submitted by: ando
While retrying, back-meta destroys the failed connection to a remote target, and
re-creates it. However, it loses the credentials, while restoring the bound DN.
As a consequence, the connection looks bound, but it's actually anonymous. A
fix is coming. The fix either preserves the credentials, when rebind-as-user is
set, or turns the connection into anonymous. The latter case is of little
practical use, and should only be used in conjunction with idassert, so that in
case of retry, from that point on identity is asserted.
p.
13 years, 3 months
Re: (ITS#6571) rebind-as-user only works on first connection attempt
by masarati@aero.polimi.it
> Full_Name: Marcel Wysocki
> Version: 2.4.22
> OS: Solaris/Linux
> URL: ftp://ftp.openldap.org/incoming/
> Submission from: (NULL) (88.79.126.162)
>
>
> Hello,
>
> i have the same problem as described here:
> http://www.openldap.org/lists/openldap-software/200712/msg00283.html
>
> here are some logs:
>
> @(#) $OpenLDAP: slapd 2.4.22 (Jun 4 2010 11:56:46) $
> slapd starting
>
> Initial connection:
> ##########################
> conn=1000 fd=11 ACCEPT from IP=127.0.0.1:45654 (IP=0.0.0.0:389)
> conn=1000 op=0 BIND
> dn="uid=FOOO,ou=applications,ou=admin,ou=BAR,c=de,o=bazbaz"
> method=128
> conn=1000 op=0 BIND
> dn="uid=FOOO,ou=applications,ou=admin,ou=BAR,c=de,o=bazbaz"
> mech=SIMPLE ssf=0
> conn=1000 op=0 RESULT tag=97 err=0 text=
> ##########################
>
> First ldapsearch:
> ##########################
> conn=1000 op=2 SRCH base="ou=users,ou=BAR,c=de,o=bazbaz" scope=1 deref=3
> filter="(mobile=491721000227)"
> conn=1000 op=2 SRCH attr=objectclass
> conn=1000 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
> ##########################
>
> backend server has been restarted, sencond ldapsearch:
> ##########################
> conn=1000 op=3 SRCH base="ou=users,ou=BAR,c=de,o=bazbaz" scope=1 deref=3
> filter="(mobile=491721000227)"
> conn=1000 op=3 SRCH attr=objectclass
> conn=1000 op=3 ldap_back_retry: retrying URI="ldap://10.2.163.13:389"
> DN="uid=FOOO,ou=applications,ou=admin,ou=BAR,c=de,o=bazbaz"
> conn=1000 op=3 SEARCH RESULT tag=101 err=0 nentries=1 text=
> ##########################
>
> backend server has been stopped, third ldapsearch, fails as it should:
> ##########################
> conn=1000 op=4 SRCH base="ou=users,ou=BAR,c=de,o=bazbaz" scope=1 deref=3
> filter="(mobile=491721000227)"
> conn=1000 op=4 SRCH attr=objectclass
> conn=1000 op=4 ldap_back_retry: retrying URI="ldap://10.2.163.13:389"
> DN="uid=FOOO,ou=applications,ou=admin,ou=BAR,c=de,o=bazbaz"
> conn=1000 op=4 SEARCH RESULT tag=101 err=52 nentries=0 text=
> ##########################
>
> backend server has been restarted, fourth ldapsearch, rebind fails:
> ##########################
> conn=1000 op=5 SRCH base="ou=users,ou=BAR,c=de,o=bazbaz" scope=1 deref=3
> filter="(mobile=491721000227)"
> conn=1000 op=5 SRCH attr=objectclass
> conn=1000 op=5 ldap_back_dobind_int:
> DN="uid=FOOO,ou=applications,ou=admin,ou=BAR,c=de,o=bazbaz" without creds,
> binding anonymously
> conn=1000 op=5 SEARCH RESULT tag=101 err=0 nentries=0 text=
> ##########################
>
> following the configuration for back-ldap:
>
> database ldap
> suffix "o=bazbaz"
> uri ldap://10.2.163.13:389
> rootdn "cn=PEX,o=bazbaz"
> rootpw secret
> idle-timeout 301
> rebind-as-user yes
> single-conn yes
> chase-referrals no
> acl-bind bindmethod=simple
> binddn="uid=FOOO,ou=applications,ou=admin,ou=BAR,c=de,o=bazbaz"
> credentials=supersecret
I don't clearly see why you consider this behavior incorrect. As soon as
the client receives a err=52 (LDAP_UNAVAILABLE), the connection is
compromised. Back-ldap destroys the cached connection, since it does not
work. As a consequence, the related credentials are forgotten. The
client should give up, as the proxy already retried and failed (if it
succeeded, the whole point would be moot, as the client wouldn't even know
that the connection between the proxy and the remote server was broken).
p.
13 years, 3 months
Re: (ITS#6548) Many "connection_read(): no connection!" warnings when using ldapi:/// and a bind DN (no external authentication)
by online@mark.ziesemer.com
--0050450171a831aa7e0488f30c72
Content-Type: text/plain; charset=ISO-8859-1
On Sun, Jun 13, 2010 at 5:20 PM, Howard Chu <hyc(a)symas.com> wrote:
> Mark A. Ziesemer wrote:
>
>> On Wed, May 12, 2010 at 10:05 AM, Howard Chu <hyc(a)symas.com
>> <mailto:hyc@symas.com>> wrote:
>>
>>
>> online(a)mark.ziesemer.com <mailto:online@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 was not happening under a high load, but with only 1-2 connections
>> active.
>>
>> I might not have focused on it enough in the original report, but isn't
>> this
>> looking like it is probably an issue with the libldap client library
>> (provided
>> by OpenLDAP), rather than the slapd daemon? Looking at the provided logs,
>> it
>> appears that no do_unbind request is received (not sent by the client)
>> when
>> using ldapi:/// with a bind DN.
>>
>> If it can't / won't be fixed, can the logging of the "connection_read():
>> no
>> connection!" event in slapd at least be demoted to a lower level so that
>> it
>> doesn't fill the default logging output, without having to change the
>> overall
>> configured logging level and potentially missing other logged events that
>> do
>> require attention?
>>
>
> "Fixing" libldap, if there's even a bug there, obviously won't help with
> other clients using non-OpenLDAP libraries. At any rate, there's nothing
> that requires an Unbind request to be sent, so there's no bug here.
>
As stated by one of the other OpenLDAP engineers in the above link, the
recommendation was to "fix whatever client is disconnecting without
unbinding". In this case, the client is the OpenLDAP libraries. Please at
least re-consider for fixing, even in a "help wanted" or "pending" status,
rather than just closing. Either the client library should be fixed to send
an unbind before disconnecting in all circumstances (i.e. ldapi:/// as well
as ldap:///), or it should be confirmed and documented that the unbind is
not necessary, in which case the server should be fixed to not output the
"connection_read(): no connection!" events at the default logging level.
I don't see messages filling the log. I don't see any issue here at all.
>
I'm not the only one seeing this. My link to the OpenLDAP mailing list
above, as well as Gergely's inquiry into this ITS are 2 directly related
occurrences observed by others.
I was only able to reproduce this by performing a Bind with invalid
> credentials. In the case with correct credentials, there were no extraneous
> messages. If you're seeing a lot of these cases, then you should think about
> why you're getting a lot of Binds with invalid passwords. Fix the problem,
> not the symptom. This ITS will be closed.
While this may be true, in any production environment, you can almost be
guaranteed that there will be login attempts with invalid credentials - even
just due to users mistyping their password on occasion, using CAPS lock,
etc. Again, the log entry should either be suppressed at the default
logging level (preferred), or at least re-worded to something more
meaningful, e.g. "Received invalid login attempt; disconnecting client".
However, even then, this should be made to work the same regardless of
protocol used for consistency.
This may not be a high priority or interesting issue to fix, but please
don't simply ignore what seems to be a very reasonable request. If this
issue is not addressed, the effect becomes training other users and admins
to ignore the logs if they regularly contain trivial updates at the default
level - which I hope we can agree is not a good practice.
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/
--
Mark A. Ziesemer
www.ziesemer.com
--0050450171a831aa7e0488f30c72
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable
<br><div class=3D"gmail_quote">On Sun, Jun 13, 2010 at 5:20 PM, Howard Chu =
<span dir=3D"ltr"><<a href=3D"mailto:hyc@symas.com">hyc(a)symas.com</a>>=
;</span> wrote:<br><blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0=
pt 0pt 0.8ex; border-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;=
">
Mark A. Ziesemer wrote:<br>
<blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0pt 0pt 0.8ex; borde=
r-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;"><div class=3D"im"=
>
On Wed, May 12, 2010 at 10:05 AM, Howard Chu <<a href=3D"mailto:hyc@syma=
s.com" target=3D"_blank">hyc(a)symas.com</a><br></div>
<mailto:<a href=3D"mailto:hyc@symas.com" target=3D"_blank">hyc(a)symas.com=
</a>>> wrote:<div><div></div><div class=3D"h5"><br>
<br>
=A0 =A0<a href=3D"mailto:online@mark.ziesemer.com" target=3D"_blank">onlin=
e(a)mark.ziesemer.com</a> <mailto:<a href=3D"mailto:online@mark.ziesemer.c=
om" target=3D"_blank">online(a)mark.ziesemer.com</a>> wrote:<br>
<br>
=A0 =A0 =A0 =A0Full_Name: Mark A. Ziesemer<br>
=A0 =A0 =A0 =A0Version: 2.4.21<br>
=A0 =A0 =A0 =A0OS: Ubuntu Linux 10.04<br>
=A0 =A0 =A0 =A0URL: <a href=3D"ftp://ftp.openldap.org/incoming/" target=3D=
"_blank">ftp://ftp.openldap.org/incoming/</a><br>
=A0 =A0 =A0 =A0Submission from: (NULL) (2001:470:1f11:3ae:4d6d:3d3e:faa6:e=
e3d)<br>
<br>
<br>
=A0 =A0 =A0 =A0Many "connection_read(): no connection!" warnings=
are written to<br>
=A0 =A0 =A0 =A0/var/log/debug<br>
=A0 =A0 =A0 =A0and /var/log/syslog by slapd. =A0As stated at<br>
=A0 =A0 =A0 =A0<a href=3D"http://www.openldap.org/lists/openldap-software/=
200811/msg00079.html" target=3D"_blank">http://www.openldap.org/lists/openl=
dap-software/200811/msg00079.html</a> ,<br>
=A0 =A0 =A0 =A0this is<br>
=A0 =A0 =A0 =A0apparently not a problem with slapd, but a client that is<b=
r>
=A0 =A0 =A0 =A0disconnecting without<br>
=A0 =A0 =A0 =A0first unbinding.<br>
<br>
<br>
=A0 =A0This also happens when the connection manager queues up a thread to=
handle<br>
=A0 =A0a "socket is readable" event on a socket that's in th=
e process of closing.<br>
=A0 =A0Pretty much unavoidable, when a lot of threads are active. I don=
9;t see<br>
=A0 =A0this as a high enough priority to warrant fixing.<br>
<br>
<br>
This was not happening under a high load, but with only 1-2 connections act=
ive.<br>
<br>
I might not have focused on it enough in the original report, but isn't=
this<br>
looking like it is probably an issue with the libldap client library (provi=
ded<br>
by OpenLDAP), rather than the slapd daemon? =A0Looking at the provided logs=
, it<br>
appears that no do_unbind request is received (not sent by the client) when=
<br>
using ldapi:/// with a bind DN.<br>
<br>
If it can't / won't be fixed, can the logging of the "connecti=
on_read(): no<br>
connection!" event in slapd at least be demoted to a lower level so th=
at it<br>
doesn't fill the default logging output, without having to change the o=
verall<br>
configured logging level and potentially missing other logged events that d=
o<br>
require attention?<br>
</div></div></blockquote>
<br>
"Fixing" libldap, if there's even a bug there, obviously won&=
#39;t help with other clients using non-OpenLDAP libraries. At any rate, th=
ere's nothing that requires an Unbind request to be sent, so there'=
s no bug here.<br>
</blockquote><div><br>As stated by one of the other OpenLDAP engineers in t=
he above link, the recommendation was to "fix whatever client is disco=
nnecting without unbinding".=A0 In this case, the client is the OpenLD=
AP libraries.=A0 Please at least re-consider for fixing, even in a "he=
lp wanted" or "pending" status, rather than just closing.=A0=
Either the client library should be fixed to send an unbind before disconn=
ecting in all circumstances (i.e. ldapi:/// as well as ldap:///), or it sho=
uld be confirmed and documented that the unbind is not necessary, in which =
case the server should be fixed to not output the "connection_read(): =
no connection!" events at the default logging level. <br>
<br></div><blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0pt 0pt 0.=
8ex; border-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;">
I don't see messages filling the log. I don't see any issue here at=
all.<br></blockquote><div><br>I'm not the only one seeing this.=A0 My =
link to the OpenLDAP mailing list above, as well as Gergely's inquiry i=
nto this ITS are 2 directly related occurrences observed by others. <br>
<br></div><blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0pt 0pt 0.=
8ex; border-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;">
I was only able to reproduce this by performing a Bind with invalid credent=
ials. In the case with correct credentials, there were no extraneous messag=
es. If you're seeing a lot of these cases, then you should think about =
why you're getting a lot of Binds with invalid passwords. Fix the probl=
em, not the symptom. This ITS will be closed.</blockquote>
<div class=3D"h5">=A0<br>While this may be true, in any production environm=
ent, you can almost be guaranteed that there will be login attempts with in=
valid credentials - even just due to users mistyping their password on occa=
sion, using CAPS lock, etc.=A0 Again, the log entry should either be suppre=
ssed at the default logging level (preferred), or at least re-worded to som=
ething more meaningful, e.g. "Received invalid login attempt; disconne=
cting client".=A0 However, even then, this should be made to work the =
same regardless of protocol used for consistency.<br>
<br>This may not be a high priority or interesting issue to fix, but please=
don't simply ignore what seems to be a very reasonable request.=A0 If =
this issue is not addressed, the effect becomes training other users and ad=
mins to ignore the logs if they regularly contain trivial updates at the de=
fault level - which I hope we can agree is not a good practice.<br>
<br>
<blockquote class=3D"gmail_quote" style=3D"margin: 0pt 0pt 0pt 0.8ex; borde=
r-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;">
=A0 =A0 =A0 =A0This appears to be an issue with the libldap client library=
provided<br>
=A0 =A0 =A0 =A0by OpenLDAP<br>
=A0 =A0 =A0 =A0itself (2.4.21), and not the slapd daemon.<br>
<br>
=A0 =A0 =A0 =A0Issue is reproducible even by just using "ldapsearch -=
H ldapi:///",<br>
=A0 =A0 =A0 =A0but only if<br>
=A0 =A0 =A0 =A0a bind DN is specified (-D) and external authentication is =
not used.<br>
<br>
=A0 =A0 =A0 =A0Running slapd with logging enabled (-d 8) shows the followi=
ng 3<br>
=A0 =A0 =A0 =A0sequences -<br>
=A0 =A0 =A0 =A0ldapsearch command followed by the slapd logs. =A0Note that=
the<br>
=A0 =A0 =A0 =A0"connection_read(): no connection!" is only visib=
le on the middle pair.<br>
<br>
<br>
=A0 =A0 =A0 =A0$ ldapsearch -LLL -Y EXTERNAL -H ldapi:/// -b ""<=
br>
=A0 =A0 =A0 =A0SASL/EXTERNAL authentication started<br>
=A0 =A0 =A0 =A0SASL username: gidNumber=3D0+uidNumber=3D0,cn=3Dpeercred,cn=
=3Dexternal,cn=3Dauth<br>
=A0 =A0 =A0 =A0SASL SSF: 0<br>
=A0 =A0 =A0 =A0No such object (32)<br>
<br>
=A0 =A0 =A0 =A0slap_listener_activate(9):<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0slap_listener(ldapi:///)<br>
<br>
=A0 =A0 =A0 =A0connection_get(14): got connid=3D1000<br>
=A0 =A0 =A0 =A0connection_read(14): checking for input on id=3D1000<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0ber_get_next: tag 0x30 len 24 contents:<br>
=A0 =A0 =A0 =A0op tag 0x60, time 1273546410<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0conn=3D1000 op=3D0 do_bind<br>
=A0 =A0 =A0 =A0ber_scanf fmt ({imt) ber:<br>
=A0 =A0 =A0 =A0ber_scanf fmt ({m) ber:<br>
=A0 =A0 =A0 =A0ber_scanf fmt (m) ber:<br>
=A0 =A0 =A0 =A0ber_scanf fmt (}}) ber:<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0dnPrettyNormal:<><br>
<br>
=A0 =A0 =A0 =A0<<< =A0dnPrettyNormal:<>,<><br>
=A0 =A0 =A0 =A0do_bind: dn () SASL mech EXTERNAL<br>
=A0 =A0 =A0 =A0=3D=3D>slap_sasl2dn: converting SASL name<br>
=A0 =A0 =A0 =A0gidNumber=3D0+uidNumber=3D0,cn=3Dpeercred,cn=3Dexternal,cn=
=3Dauth to a DN<br>
=A0 =A0 =A0 =A0<=3D=3Dslap_sasl2dn: Converted SASL name to<nothing&g=
t;<br>
=A0 =A0 =A0 =A0SASL Authorize [conn=3D1000]: =A0proxy authorization allowe=
d authzDN=3D""<br>
=A0 =A0 =A0 =A0send_ldap_sasl: err=3D0 len=3D-1<br>
=A0 =A0 =A0 =A0do_bind: SASL/EXTERNAL bind:<br>
=A0 =A0 =A0 =A0dn=3D"gidNumber=3D0+uidNumber=3D0,cn=3Dpeercred,cn=3De=
xternal,cn=3Dauth" sasl_ssf=3D0<br>
=A0 =A0 =A0 =A0send_ldap_response: msgid=3D1 tag=3D97 err=3D0<br>
=A0 =A0 =A0 =A0ber_flush2: 14 bytes to sd 14<br>
=A0 =A0 =A0 =A0<=3D=3D slap_sasl_bind: rc=3D0<br>
=A0 =A0 =A0 =A0connection_get(14): got connid=3D1000<br>
=A0 =A0 =A0 =A0connection_read(14): checking for input on id=3D1000<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0ber_get_next: tag 0x30 len 37 contents:<br>
=A0 =A0 =A0 =A0op tag 0x63, time 1273546410<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0conn=3D1000 op=3D1 do_search<br>
=A0 =A0 =A0 =A0ber_scanf fmt ({miiiib) ber:<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0dnPrettyNormal:<><br>
<br>
=A0 =A0 =A0 =A0<<< =A0dnPrettyNormal:<>,<><br>
=A0 =A0 =A0 =A0ber_scanf fmt (m) ber:<br>
=A0 =A0 =A0 =A0ber_scanf fmt ({M}}) ber:<br>
=A0 =A0 =A0 =A0send_ldap_result: conn=3D1000 op=3D1 p=3D3<br>
=A0 =A0 =A0 =A0send_ldap_response: msgid=3D2 tag=3D101 err=3D32<br>
=A0 =A0 =A0 =A0ber_flush2: 14 bytes to sd 14<br>
=A0 =A0 =A0 =A0connection_get(14): got connid=3D1000<br>
=A0 =A0 =A0 =A0connection_read(14): checking for input on id=3D1000<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0ber_get_next: tag 0x30 len 5 contents:<br>
=A0 =A0 =A0 =A0op tag 0x42, time 1273546410<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0conn=3D1000 op=3D2 do_unbind<br>
=A0 =A0 =A0 =A0connection_close: conn=3D1000 sd=3D14<br>
<br>
=A0 =A0 =A0 =A0$ ldapsearch -H ldapi:/// -D "cn=3Dadmin,dc=3Dexample,=
dc=3Dcom" -b "" -W<br>
=A0 =A0 =A0 =A0Enter LDAP Password:<br>
=A0 =A0 =A0 =A0ldap_bind: Invalid credentials (49)<br>
<br>
=A0 =A0 =A0 =A0slap_listener_activate(9):<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0slap_listener(ldapi:///)<br>
<br>
=A0 =A0 =A0 =A0connection_get(14): got connid=3D1001<br>
=A0 =A0 =A0 =A0connection_read(14): checking for input on id=3D1001<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0ber_get_next: tag 0x30 len 44 contents:<br>
=A0 =A0 =A0 =A0op tag 0x60, time 1273546420<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0conn=3D1001 op=3D0 do_bind<br>
=A0 =A0 =A0 =A0ber_scanf fmt ({imt) ber:<br>
=A0 =A0 =A0 =A0ber_scanf fmt (m}) ber:<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0dnPrettyNormal:<cn=3Dadmin,dc=3D=
example,dc=3Dcom><br>
<br>
=A0 =A0 =A0 =A0<<<<br>
=A0 =A0 =A0 =A0 =A0dnPrettyNormal:<cn=3Dadmin,dc=3Dexample,dc=3Dcom>=
,<cn=3Dadmin,dc=3Dexample,dc=3Dcom><br>
=A0 =A0 =A0 =A0do_bind: version=3D3 dn=3D"cn=3Dadmin,dc=3Dexample,dc=
=3Dcom" method=3D128<br>
=A0 =A0 =A0 =A0send_ldap_result: conn=3D1001 op=3D0 p=3D3<br>
=A0 =A0 =A0 =A0send_ldap_response: msgid=3D1 tag=3D97 err=3D49<br>
=A0 =A0 =A0 =A0ber_flush2: 14 bytes to sd 14<br>
=A0 =A0 =A0 =A0connection_get(14): got connid=3D1001<br>
=A0 =A0 =A0 =A0connection_read(14): checking for input on id=3D1001<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0ber_get_next on fd 14 failed errno=3D0 (Success)<br>
=A0 =A0 =A0 =A0connection_close: conn=3D1001 sd=3D14<br>
=A0 =A0 =A0 =A0connection_read(14): no connection!<br>
=A0 =A0 =A0 =A0connection_read(14): no connection!<br>
<br>
=A0 =A0 =A0 =A0$ ldapsearch -H ldap:/// -D "cn=3Dadmin,dc=3Dexample,d=
c=3Dcom" -b "" -W<br>
=A0 =A0 =A0 =A0Enter LDAP Password:<br>
=A0 =A0 =A0 =A0ldap_bind: Invalid credentials (49)<br>
<br>
=A0 =A0 =A0 =A0slap_listener_activate(8):<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0slap_listener(ldap:///)<br>
<br>
=A0 =A0 =A0 =A0connection_get(14): got connid=3D1002<br>
=A0 =A0 =A0 =A0connection_read(14): checking for input on id=3D1002<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0ber_get_next: tag 0x30 len 44 contents:<br>
=A0 =A0 =A0 =A0op tag 0x60, time 1273546425<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0conn=3D1002 op=3D0 do_bind<br>
=A0 =A0 =A0 =A0ber_scanf fmt ({imt) ber:<br>
=A0 =A0 =A0 =A0ber_scanf fmt (m}) ber:<br>
<br>
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0dnPrettyNormal:<cn=3Dadmin,dc=3D=
example,dc=3Dcom><br>
<br>
=A0 =A0 =A0 =A0<<<<br>
=A0 =A0 =A0 =A0 =A0dnPrettyNormal:<cn=3Dadmin,dc=3Dexample,dc=3Dcom>=
,<cn=3Dadmin,dc=3Dexample,dc=3Dcom><br>
=A0 =A0 =A0 =A0do_bind: version=3D3 dn=3D"cn=3Dadmin,dc=3Dexample,dc=
=3Dcom" method=3D128<br>
=A0 =A0 =A0 =A0send_ldap_result: conn=3D1002 op=3D0 p=3D3<br>
=A0 =A0 =A0 =A0send_ldap_response: msgid=3D1 tag=3D97 err=3D49<br>
=A0 =A0 =A0 =A0ber_flush2: 14 bytes to sd 14<br>
=A0 =A0 =A0 =A0connection_get(14): got connid=3D1002<br>
=A0 =A0 =A0 =A0connection_read(14): checking for input on id=3D1002<br>
=A0 =A0 =A0 =A0ber_get_next<br>
=A0 =A0 =A0 =A0ber_get_next on fd 14 failed errno=3D0 (Success)<br>
=A0 =A0 =A0 =A0connection_close: conn=3D1002 sd=3D14<br>
</blockquote>
<br>
-- <br>
=A0-- Howard Chu<br>
=A0CTO, Symas Corp. =A0 =A0 =A0 =A0 =A0 <a href=3D"http://www.symas.com" t=
arget=3D"_blank">http://www.symas.com</a><br>
=A0Director, Highland Sun =A0 =A0 <a href=3D"http://highlandsun.com/hyc/" =
target=3D"_blank">http://highlandsun.com/hyc/</a><br>
=A0Chief Architect, OpenLDAP =A0<a href=3D"http://www.openldap.org/project=
/" target=3D"_blank">http://www.openldap.org/project/</a><br>
</div></div><br>--<br>Mark A. Ziesemer<br><a href=3D"http://www.ziesemer.co=
m">www.ziesemer.com</a><br>
<br>
--0050450171a831aa7e0488f30c72--
13 years, 3 months
Re: (ITS#6548) Many "connection_read(): no connection!" warnings when using ldapi:/// and a bind DN (no external authentication)
by hyc@symas.com
Mark A. Ziesemer wrote:
> On Wed, May 12, 2010 at 10:05 AM, Howard Chu <hyc(a)symas.com
> <mailto:hyc@symas.com>> wrote:
>
> online(a)mark.ziesemer.com <mailto:online@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 was not happening under a high load, but with only 1-2 connections active.
>
> I might not have focused on it enough in the original report, but isn't this
> looking like it is probably an issue with the libldap client library (provided
> by OpenLDAP), rather than the slapd daemon? Looking at the provided logs, it
> appears that no do_unbind request is received (not sent by the client) when
> using ldapi:/// with a bind DN.
>
> If it can't / won't be fixed, can the logging of the "connection_read(): no
> connection!" event in slapd at least be demoted to a lower level so that it
> doesn't fill the default logging output, without having to change the overall
> configured logging level and potentially missing other logged events that do
> require attention?
"Fixing" libldap, if there's even a bug there, obviously won't help with other
clients using non-OpenLDAP libraries. At any rate, there's nothing that
requires an Unbind request to be sent, so there's no bug here.
I don't see messages filling the log. I don't see any issue here at all.
I was only able to reproduce this by performing a Bind with invalid
credentials. In the case with correct credentials, there were no extraneous
messages. If you're seeing a lot of these cases, then you should think about
why you're getting a lot of Binds with invalid passwords. Fix the problem, not
the symptom. This ITS will be closed.
> 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/
13 years, 3 months