Issue 6599 - slapd not responding
Summary: slapd not responding
Status: VERIFIED WONTFIX
Alias: None
Product: OpenLDAP
Classification: Unclassified
Component: slapd (show other issues)
Version: 2.4.21
Hardware: All All
: --- normal
Target Milestone: ---
Assignee: OpenLDAP project
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-07-23 13:13 UTC by binoyme@gmail.com
Modified: 2020-03-19 19:57 UTC (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this issue.
Description binoyme@gmail.com 2010-07-23 13:13:17 UTC
Full_Name: Binoy Joseph
Version: 2.4.21
OS: Linux
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (210.210.79.19)


I run OpenLDAP 2.4.21 configured to bdb on Windows and Linux. We run some
applications on top of our application framework which in turn is connected to
OpenLDAP via JLDAP. We list children of 'cn=soap nodes' (search LDAP) very often
as shown in the DIT below. I wrote a test case to create soapnode, soapproc,
connectionpoint and then delete them one after the other, ie I create set1,
delete set1, create set2, delete set2... Note that list children of 'cn=soap
nodes' happen in parallel as mentioned above.

Randomly but very consistently, suddenly we face an LDAP not responding issue.
When I connect via an LDAP Explorer, I am able to see and expand most of the
LDAP entries, except the 'cn=soap nodes' as shown in the DIT below, which says
LDAP query did not return indefinitely. CPU: slapd shoots to 50% in Windows and
100% in Linux. Then I have to kill slapd and start again.

This does not happen in OpenLDAP 2.4.16. After upgrading to 2.4.21 this started
happening. When I switched to hdb, this does not occur in Linux, but continues
to happen in Windows.
This also looks very similar to
http://www.openldap.org/its/index.cgi?findid=6322, Subject: slapd suddenly stops
working, and starts using 100% CPU.

o=org1
|
+-cn=soap nodes
   |
   +-cn=soapnode1
   |  |
   |  +cn=soapproc1
   |    |
   |    +cn=connectionpoint1
   |
   +-cn=soapnode2
   .
   .

Thanks and regards,
Binoy Joseph
Comment 1 Quanah Gibson-Mount 2010-07-26 15:48:18 UTC
--On Friday, July 23, 2010 1:13 PM +0000 binoy@cordys.com wrote:

> Full_Name: Binoy Joseph
> Version: 2.4.21
> OS: Linux
> URL: ftp://ftp.openldap.org/incoming/
> Submission from: (NULL) (210.210.79.19)

Can you reproduce this with OpenLDAP 2.4.23?  There was a change in locking 
behavior introduced in 2.4.21 that was backed out in 2.4.23.

--Quanah


--

Quanah Gibson-Mount
Principal Software Engineer
Zimbra, Inc
--------------------
Zimbra ::  the leader in open source messaging and collaboration

Comment 2 binoyme@gmail.com 2010-07-27 13:34:55 UTC
Hi Quanah,

Thanks a lot for your reply.
Looks like the issue does not appear with OpenLDAP 2.4.23 and BDB in Linux.
But somehow the issue still occurs in Windows.
Can you mention which file/issue you are talking about regarding the locking
behavior you mentioned?

Thanks and regards,
Binoy Joseph


On Mon, Jul 26, 2010 at 9:18 PM, Quanah Gibson-Mount <quanah@zimbra.com>wrote:

> --On Friday, July 23, 2010 1:13 PM +0000 binoy@cordys.com wrote:
>
>  Full_Name: Binoy Joseph
>> Version: 2.4.21
>> OS: Linux
>> URL: ftp://ftp.openldap.org/incoming/
>> Submission from: (NULL) (210.210.79.19)
>>
>
> Can you reproduce this with OpenLDAP 2.4.23?  There was a change in locking
> behavior introduced in 2.4.21 that was backed out in 2.4.23.
>
> --Quanah
>
>
> --
>
> Quanah Gibson-Mount
> Principal Software Engineer
> Zimbra, Inc
> --------------------
> Zimbra ::  the leader in open source messaging and collaboration
>
Comment 3 Quanah Gibson-Mount 2010-07-27 19:19:42 UTC
--On Tuesday, July 27, 2010 7:04 PM +0530 Binoy Joseph <binoy@cordys.com> 
wrote:

>
> Hi Quanah,
>
>
> Thanks a lot for your reply.
> Looks like the issue does not appear with OpenLDAP 2.4.23 and BDB in
> Linux.
> But somehow the issue still occurs in Windows.
> Can you mention which file/issue you are talking about regarding the
> locking behavior you mentioned?
> Thanks and regards,
> Binoy Joseph

ITS#6577

--Quanah

--

Quanah Gibson-Mount
Principal Software Engineer
Zimbra, Inc
--------------------
Zimbra ::  the leader in open source messaging and collaboration

Comment 4 binoyme@gmail.com 2010-07-28 13:09:15 UTC
Hi,

1) I downloaded OpenLDAP 2.4.23
(20100719)<ftp://ftp.openldap.org/pub/OpenLDAP/openldap-stable/openldap-stable-20100719.tgz>
. I checked servers/slapd/back-bdb/cache.c. I see that the fix for ITS#6577
dated July 1 is not available in the release build. I checked out the latest
sources and did a build and tested.

2) The issue still persists in Windows. Here are some useful logs.

==============================================================================
This is a SUCCESSFUL scenario:

conn=1000 op=8703 DEL dn="cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
bdb_dn2entry("cn=test220,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com")
==> hdb_delete: cn=Test220,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com
slap_queue_csn: queing 034EFC7C 20100728123751.496923Z#000000#000#000000
bdb_dn2entry("cn=test220,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com")
=> access_allowed: delete access to "cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "children" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> access_allowed: delete access to "cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "entry" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> hdb_dn2id_delete 0xa96: "cn=test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
<= hdb_dn2id_delete 0xa96: 0
=> index_entry_del( 2710, "cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" )
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [a0795064]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [78d8fcbf]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [26382a68]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [b9195d83]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [64447e0e]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [815b06f7]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [403d84ed]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [600c0260]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [d66e2c29]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [547b3983]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [1610f370]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [0096defd]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [f612c92d]
<= key_change 0
<= index_entry_del( 2710, "cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" ) success
====> bdb_cache_delete( 2710 )
hdb_delete: deleted id=00000a96 dn="cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
send_ldap_result: conn=1000 op=8703 p=3
send_ldap_result: err=0 matched="" text=""
send_ldap_response: msgid=43189 tag=107 err=0
ber_flush2: 16 bytes to sd 1832
  0000:  30 0e 02 03 00 a8 b5 6b  07 0a 01 00 04 00 04 00   0......k........

tls_write: want=90, written=90
  0000:  17 03 01 00 20 d3 72 46  5c 99 ae 97 cd 90 f5 64   .... .rF\......d

  0010:  47 53 38 1d 26 6c c7 d4  21 45 28 e2 27 31 bd 5f   GS8.&l..!E(.'1._

  0020:  bc c4 92 eb 6e 17 03 01  00 30 e5 be 97 76 6c cc   ....n....0...vl.

  0030:  29 c0 21 05 d9 f6 55 d6  2a dc d5 68 0b f6 73 6a   ).!...U.*..h..sj

  0040:  7f ff 24 8b fa 9e 57 41  27 ee d3 9a e5 9a 17 11   ..$...WA'.......

  0050:  ee 87 0d 55 ae 98 81 53  2d 7d                     ...U...S-}

ldap_write: want=16, written=16
  0000:  30 0e 02 03 00 a8 b5 6b  07 0a 01 00 04 00 04 00   0......k........

conn=1000 op=8703 RESULT tag=107 err=0 text=
slap_graduate_commit_csn: removing 015CFFC8
20100728123751.496923Z#000000#000#000000
daemon: activity on 6 descriptors
daemon: activity on: 5r
daemon: read activity on 5
daemon: WSselect: listen=2 active_threads=0 tvp=NULL
connection_get(5)
daemon: WSselect: listen=3 active_threads=0 tvp=NULL
connection_get(5): got connid=1000
daemon: WSselect: listen=4 active_threads=0 tvp=NULL
connection_read(5): checking for input on id=1000
======================================================================================

======================================================================================
This is where it FAILS


conn=1000 op=9270 DEL dn="cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
bdb_dn2entry("cn=test367,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com")
==> hdb_delete: cn=Test367,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com
slap_queue_csn: queing 0420FC7C 20100728110306.101543Z#000000#000#000000
bdb_dn2entry("cn=test367,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com")
daemon: activity on 6 descriptors
daemon: activity on: 5r
daemon: read activity on 5
daemon: WSselect: listen=2 active_threads=0 tvp=NULL
daemon: WSselect: listen=3 active_threads=0 tvp=NULL
daemon: WSselect: listen=4 active_threads=0 tvp=NULL
connection_get(5)
connection_get(5): got connid=1000
connection_read(5): checking for input on id=1000
ber_get_next
tls_read: want=5, got=5
 .....
op tag 0x63, time 1280314986
ber_get_next
tls_read: want=5 error=Unknown error
ldap_read: want=8 error=Unknown error
daemon: activity on 1 descriptor
daemon: waked
daemon: WSselect: listen=2 active_threads=0 tvp=NULL
daemon: WSselect: listen=3 active_threads=0 tvp=NULL
daemon: WSselect: listen=4 active_threads=0 tvp=NULL
=> access_allowed: delete access to "cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "children" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> access_allowed: delete access to "cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "entry" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> hdb_dn2id_delete 0xc4b: "cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
<= hdb_dn2id_delete 0xc4b: 0
=> index_entry_del( 3147, "cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" )
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [aec1526a]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [78d8fcbf]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [27382a68]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [ce175d82]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [2230817c]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [815b06f7]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [8b4384f1]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [600c0260]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [58802faf]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [547b3983]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [9821f6f6]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [0096defd]
conn=1000 op=9271 do_search
ber_scanf fmt ({miiiib) ber:
ber_dump: buf=015AAF30 ptr=015AAF34 end=015AAFA5 len=113
  0000:  63 6f 04 4e 63 6e 3d 54  65 73 74 33 36 37 2c 63   co.Ncn=Test367,c

  0010:  6e 3d 54 65 73 74 33 36  37 2c 63 6e 3d 73 6f 61   n=Test367,cn=soa

  0020:  70 20 6e 6f 64 65 73 2c  6f 3d 73 79 73 74 65 6d   p nodes,o=system

  0030:  2c 63 6e 3d 63 6f 72 64  79 73 2c 63 6e 3d 74 32   ,cn=cordys,cn=t2

  0040:  37 34 2c 6f 3d 76 61 6e  65 6e 62 75 72 67 2e 63   74,o=vanenburg.c

  0050:  6f 6d 0a 01 00 0a 01 00  02 02 07 d0 02 01 00 01   om..............

  0060:  01 00 87 0b 6f 62 6a 65  63 74 63 6c 61 73 73 30   ....objectclass0

  0070:  00                                                 .

>>> dnPrettyNormal: <cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com>
=> ldap_bv2dn(cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com,0)
<= ldap_bv2dn(cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=test367,cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com)=0
<<< dnPrettyNormal: <cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com>,
<cn=test367,cn=test367,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com>
SRCH "cn=Test367,cn=Test367,cn=soap nodes,o=system,cn=cordys,cn=t274,o=
vanenburg.com" 0 0    2000 0 0
begin get_filter
PRESENT
ber_scanf fmt (m) ber:
ber_dump: buf=015AAF30 ptr=015AAF96 end=015AAFA5 len=15
  0000:  87 0b 6f 62 6a 65 63 74  63 6c 61 73 73 30 00      ..objectclass0.

end get_filter 0
    filter: (objectClass=*)
ber_scanf fmt ({M}}) ber:
ber_dump: buf=015AAF30 ptr=015AAFA3 end=015AAFA5 len=2
  0000:  00 00                                              ..

    attrs:
conn=1000 op=9271 SRCH base="cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" scope=0 deref=0
filter="(objectClass=*)"
=> hdb_search
bdb_dn2entry("cn=test367,cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
=> hdb_dn2id("cn=test367,cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [f612c92d]
<= key_change 0
<= index_entry_del( 3147, "cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" ) success

=======================================================================================

Please help.

Thanks and regards,

Binoy Joseph
Sr. Software Engineer
T +91 406656 1498 • M +91 9849176132


On Wed, Jul 28, 2010 at 12:49 AM, Quanah Gibson-Mount <quanah@zimbra.com>wrote:

> --On Tuesday, July 27, 2010 7:04 PM +0530 Binoy Joseph <binoy@cordys.com>
> wrote:
>
>
>> Hi Quanah,
>>
>>
>> Thanks a lot for your reply.
>> Looks like the issue does not appear with OpenLDAP 2.4.23 and BDB in
>> Linux.
>> But somehow the issue still occurs in Windows.
>> Can you mention which file/issue you are talking about regarding the
>> locking behavior you mentioned?
>> Thanks and regards,
>> Binoy Joseph
>>
>
> ITS#6577
>
>
> --Quanah
>
> --
>
> Quanah Gibson-Mount
> Principal Software Engineer
> Zimbra, Inc
> --------------------
> Zimbra ::  the leader in open source messaging and collaboration
>
Comment 5 binoyme@gmail.com 2010-07-28 13:15:08 UTC
Sending 1 more time as plain text.

Thanks and regards,

Binoy Joseph
Sr. Software Engineer
T +91 406656 1498 • M +91 9849176132


---------- Forwarded message ----------
From: Binoy Joseph <binoy@cordys.com>
Date: Wed, Jul 28, 2010 at 6:39 PM
Subject: Re: (ITS#6599) slapd not responding
To: openldap-its@openldap.org


Hi,
1) I downloaded OpenLDAP 2.4.23 (20100719). I checked
servers/slapd/back-bdb/cache.c. I see that the fix for ITS#6577 dated
July 1 is not available in the release build. I checked out the latest
sources and did a build and tested.
2) The issue still persists in Windows. Here are some useful logs.
==============================================================================
This is a SUCCESSFUL scenario:
conn=1000 op=8703 DEL dn="cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
bdb_dn2entry("cn=test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
==> hdb_delete: cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com
slap_queue_csn: queing 034EFC7C 20100728123751.496923Z#000000#000#000000
bdb_dn2entry("cn=test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
=> access_allowed: delete access to "cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "children" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> access_allowed: delete access to "cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "entry" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> hdb_dn2id_delete 0xa96: "cn=test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
<= hdb_dn2id_delete 0xa96: 0
=> index_entry_del( 2710, "cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" )
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [a0795064]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [78d8fcbf]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [26382a68]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [b9195d83]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [64447e0e]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [815b06f7]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [403d84ed]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [600c0260]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [d66e2c29]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [547b3983]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [1610f370]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [0096defd]
<= key_change 0
=> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [f612c92d]
<= key_change 0
<= index_entry_del( 2710, "cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" ) success
====> bdb_cache_delete( 2710 )
hdb_delete: deleted id=00000a96 dn="cn=Test220,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
send_ldap_result: conn=1000 op=8703 p=3
send_ldap_result: err=0 matched="" text=""
send_ldap_response: msgid=43189 tag=107 err=0
ber_flush2: 16 bytes to sd 1832
  0000:  30 0e 02 03 00 a8 b5 6b  07 0a 01 00 04 00 04 00   0......k........
tls_write: want=90, written=90
  0000:  17 03 01 00 20 d3 72 46  5c 99 ae 97 cd 90 f5 64   .... .rF\......d
  0010:  47 53 38 1d 26 6c c7 d4  21 45 28 e2 27 31 bd 5f   GS8.&l..!E(.'1._
  0020:  bc c4 92 eb 6e 17 03 01  00 30 e5 be 97 76 6c cc   ....n....0...vl.
  0030:  29 c0 21 05 d9 f6 55 d6  2a dc d5 68 0b f6 73 6a   ).!...U.*..h..sj
  0040:  7f ff 24 8b fa 9e 57 41  27 ee d3 9a e5 9a 17 11   ..$...WA'.......
  0050:  ee 87 0d 55 ae 98 81 53  2d 7d                     ...U...S-}
ldap_write: want=16, written=16
  0000:  30 0e 02 03 00 a8 b5 6b  07 0a 01 00 04 00 04 00   0......k........
conn=1000 op=8703 RESULT tag=107 err=0 text=
slap_graduate_commit_csn: removing 015CFFC8
20100728123751.496923Z#000000#000#000000
daemon: activity on 6 descriptors
daemon: activity on: 5r
daemon: read activity on 5
daemon: WSselect: listen=2 active_threads=0 tvp=NULL
connection_get(5)
daemon: WSselect: listen=3 active_threads=0 tvp=NULL
connection_get(5): got connid=1000
daemon: WSselect: listen=4 active_threads=0 tvp=NULL
connection_read(5): checking for input on id=1000
======================================================================================
======================================================================================
This is where it FAILS

conn=1000 op=9270 DEL dn="cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
bdb_dn2entry("cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
==> hdb_delete: cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com
slap_queue_csn: queing 0420FC7C 20100728110306.101543Z#000000#000#000000
bdb_dn2entry("cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
daemon: activity on 6 descriptors
daemon: activity on: 5r
daemon: read activity on 5
daemon: WSselect: listen=2 active_threads=0 tvp=NULL
daemon: WSselect: listen=3 active_threads=0 tvp=NULL
daemon: WSselect: listen=4 active_threads=0 tvp=NULL
connection_get(5)
connection_get(5): got connid=1000
connection_read(5): checking for input on id=1000
ber_get_next
tls_read: want=5, got=5
 .....
op tag 0x63, time 1280314986
ber_get_next
tls_read: want=5 error=Unknown error
ldap_read: want=8 error=Unknown error
daemon: activity on 1 descriptor
daemon: waked
daemon: WSselect: listen=2 active_threads=0 tvp=NULL
daemon: WSselect: listen=3 active_threads=0 tvp=NULL
daemon: WSselect: listen=4 active_threads=0 tvp=NULL
=> access_allowed: delete access to "cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "children" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> access_allowed: delete access to "cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" "entry" requested
<= root access granted
=> access_allowed: delete access granted by manage(=mwrscxd)
=> hdb_dn2id_delete 0xc4b: "cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com"
<= hdb_dn2id_delete 0xc4b: 0
=> index_entry_del( 3147, "cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" )
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [aec1526a]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [78d8fcbf]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [27382a68]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [ce175d82]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [2230817c]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [815b06f7]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [8b4384f1]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [600c0260]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [58802faf]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [547b3983]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [9821f6f6]
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [0096defd]
conn=1000 op=9271 do_search
ber_scanf fmt ({miiiib) ber:
ber_dump: buf=015AAF30 ptr=015AAF34 end=015AAFA5 len=113
  0000:  63 6f 04 4e 63 6e 3d 54  65 73 74 33 36 37 2c 63   co.Ncn=Test367,c
  0010:  6e 3d 54 65 73 74 33 36  37 2c 63 6e 3d 73 6f 61   n=Test367,cn=soa
  0020:  70 20 6e 6f 64 65 73 2c  6f 3d 73 79 73 74 65 6d   p nodes,o=system
  0030:  2c 63 6e 3d 63 6f 72 64  79 73 2c 63 6e 3d 74 32   ,cn=cordys,cn=t2
  0040:  37 34 2c 6f 3d 76 61 6e  65 6e 62 75 72 67 2e 63   74,o=vanenburg.c
  0050:  6f 6d 0a 01 00 0a 01 00  02 02 07 d0 02 01 00 01   om..............
  0060:  01 00 87 0b 6f 62 6a 65  63 74 63 6c 61 73 73 30   ....objectclass0
  0070:  00                                                 .
>>> dnPrettyNormal: <cn=Test367,cn=Test367,cn=soap nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com>
=> ldap_bv2dn(cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com,0)
<= ldap_bv2dn(cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=test367,cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com)=0
<<< dnPrettyNormal: <cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com>,
<cn=test367,cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com>
SRCH "cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" 0 0    2000 0 0
begin get_filter
PRESENT
ber_scanf fmt (m) ber:
ber_dump: buf=015AAF30 ptr=015AAF96 end=015AAFA5 len=15
  0000:  87 0b 6f 62 6a 65 63 74  63 6c 61 73 73 30 00      ..objectclass0.
end get_filter 0
    filter: (objectClass=*)
ber_scanf fmt ({M}}) ber:
ber_dump: buf=015AAF30 ptr=015AAFA3 end=015AAFA5 len=2
  0000:  00 00                                              ..
    attrs:
conn=1000 op=9271 SRCH base="cn=Test367,cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" scope=0 deref=0
filter="(objectClass=*)"
=> hdb_search
bdb_dn2entry("cn=test367,cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
=> hdb_dn2id("cn=test367,cn=test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com")
<= key_change 0
=> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [f612c92d]
<= key_change 0
<= index_entry_del( 3147, "cn=Test367,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com" ) success
=======================================================================================
Please help.
Thanks and regards,

Binoy Joseph
Sr. Software Engineer
T +91 406656 1498 • M +91 9849176132


On Wed, Jul 28, 2010 at 12:49 AM, Quanah Gibson-Mount <quanah@zimbra.com> wrote:
>
> --On Tuesday, July 27, 2010 7:04 PM +0530 Binoy Joseph <binoy@cordys.com> wrote:
>
>>
>> Hi Quanah,
>>
>>
>> Thanks a lot for your reply.
>> Looks like the issue does not appear with OpenLDAP 2.4.23 and BDB in
>> Linux.
>> But somehow the issue still occurs in Windows.
>> Can you mention which file/issue you are talking about regarding the
>> locking behavior you mentioned?
>> Thanks and regards,
>> Binoy Joseph
>
> ITS#6577
>
> --Quanah
>
> --
>
> Quanah Gibson-Mount
> Principal Software Engineer
> Zimbra, Inc
> --------------------
> Zimbra ::  the leader in open source messaging and collaboration

Comment 6 binoyme@gmail.com 2010-07-28 13:57:36 UTC
Hi,

In short, this works:

Deleting cn=Test0,cn=Test0,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com
Deleted cn=Test0,cn=Test0,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com

While this fails:

Deleting cn=Test2,cn=soap nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com
Searching cn=Test2,cn=Test2,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com 0 (objectclass=*)
Searched cn=Test2,cn=Test2,cn=soap
nodes,o=system,cn=cordys,cn=t274,o=vanenburg.com 0 (objectclass=*)
LDAP Connection error happend LDAPException: Connection lost waiting
for results from cin0575.vanenburg.com:6,366 (91) Connect Error
java.net.SocketException: Connection reset


Thanks and regards,
Binoy Joseph

Comment 7 Quanah Gibson-Mount 2017-03-28 00:30:29 UTC
Hi Binoy,

Sorry that this dropped off the radar for so long.  Are you still seeing 
this issue in Windows with the current OpenLDAP release?

Thanks,
Quanah

--

Quanah Gibson-Mount
Product Architect
Symas Corporation
Packaged, certified, and supported LDAP solutions powered by OpenLDAP:
<http://www.symas.com>


Comment 8 Quanah Gibson-Mount 2017-03-28 00:30:41 UTC
moved from Incoming to Software Bugs
Comment 9 Quanah Gibson-Mount 2020-03-19 19:57:31 UTC
Hello,

If you can reproduce this issue with back-mdb please reopen.  back-bdb is deprecated and removed for the forthcoming 2.5 release series.