Fwd: (ITS#6599) slapd not responding

[binoy@cordys.com]

Sending 1 more time as plain text.

Thanks and regards,

Binoy Joseph
Sr. Software Engineer
T +91 406656 1498 =95 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=A02.4.23 (20100719).=A0I checked
servers/slapd/back-bdb/cache.c. I see that the fix for=A0ITS#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.
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D
This is a SUCCESSFUL scenario:
conn=3D1000 op=3D8703 DEL dn=3D"cn=3DTest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com"
bdb_dn2entry("cn=3Dtest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com")
=3D=3D> hdb_delete: cn=3DTest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com
slap_queue_csn: queing 034EFC7C 20100728123751.496923Z#000000#000#000000
bdb_dn2entry("cn=3Dtest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com")
=3D> access_allowed: delete access to "cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" "children" reques=
ted
<=3D root access granted
=3D> access_allowed: delete access granted by manage(=3Dmwrscxd)
=3D> access_allowed: delete access to "cn=3DTest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" "entry" requested
<=3D root access granted
=3D> access_allowed: delete access granted by manage(=3Dmwrscxd)
=3D> hdb_dn2id_delete 0xa96: "cn=3Dtest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com"
<=3D hdb_dn2id_delete 0xa96: 0
=3D> index_entry_del( 2710, "cn=3DTest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" )
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [a0795064]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [78d8fcbf]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [26382a68]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [b9195d83]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [64447e0e]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [815b06f7]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [403d84ed]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [600c0260]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [d66e2c29]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [547b3983]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [1610f370]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [0096defd]
<=3D key_change 0
=3D> key_change(DELETE,a96)
bdb_idl_delete_key: a96 [f612c92d]
<=3D key_change 0
<=3D index_entry_del( 2710, "cn=3DTest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" ) success
=3D=3D=3D=3D> bdb_cache_delete( 2710 )
hdb_delete: deleted id=3D00000a96 dn=3D"cn=3DTest220,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com"
send_ldap_result: conn=3D1000 op=3D8703 p=3D3
send_ldap_result: err=3D0 matched=3D"" text=3D""
send_ldap_response: msgid=3D43189 tag=3D107 err=3D0
ber_flush2: 16 bytes to sd 1832
=A0=A00000: =A030 0e 02 03 00 a8 b5 6b =A007 0a 01 00 04 00 04 00 =A0 0....=
..k........
tls_write: want=3D90, written=3D90
=A0=A00000: =A017 03 01 00 20 d3 72 46 =A05c 99 ae 97 cd 90 f5 64 =A0 .... =
.rF\......d
=A0=A00010: =A047 53 38 1d 26 6c c7 d4 =A021 45 28 e2 27 31 bd 5f =A0 GS8.&=
l..!E(.'1._
=A0=A00020: =A0bc c4 92 eb 6e 17 03 01 =A000 30 e5 be 97 76 6c cc =A0 ....n=
....0...vl.
=A0=A00030: =A029 c0 21 05 d9 f6 55 d6 =A02a dc d5 68 0b f6 73 6a =A0 ).!..=
.U.*..h..sj
=A0=A00040: =A07f ff 24 8b fa 9e 57 41 =A027 ee d3 9a e5 9a 17 11 =A0 ..$..=
.WA'.......
=A0=A00050: =A0ee 87 0d 55 ae 98 81 53 =A02d 7d =A0 =A0 =A0 =A0 =A0 =A0 =A0=
 =A0 =A0 =A0 ...U...S-}
ldap_write: want=3D16, written=3D16
=A0=A00000: =A030 0e 02 03 00 a8 b5 6b =A007 0a 01 00 04 00 04 00 =A0 0....=
..k........
conn=3D1000 op=3D8703 RESULT tag=3D107 err=3D0 text=3D
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=3D2 active_threads=3D0 tvp=3DNULL
connection_get(5)
daemon: WSselect: listen=3D3 active_threads=3D0 tvp=3DNULL
connection_get(5): got connid=3D1000
daemon: WSselect: listen=3D4 active_threads=3D0 tvp=3DNULL
connection_read(5): checking for input on id=3D1000
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
This is where it FAILS

conn=3D1000 op=3D9270 DEL dn=3D"cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com"
bdb_dn2entry("cn=3Dtest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com")
=3D=3D> hdb_delete: cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com
slap_queue_csn: queing 0420FC7C 20100728110306.101543Z#000000#000#000000
bdb_dn2entry("cn=3Dtest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com")
daemon: activity on 6 descriptors
daemon: activity on: 5r
daemon: read activity on 5
daemon: WSselect: listen=3D2 active_threads=3D0 tvp=3DNULL
daemon: WSselect: listen=3D3 active_threads=3D0 tvp=3DNULL
daemon: WSselect: listen=3D4 active_threads=3D0 tvp=3DNULL
connection_get(5)
connection_get(5): got connid=3D1000
connection_read(5): checking for input on id=3D1000
ber_get_next
tls_read: want=3D5, got=3D5
=A0.....
op tag 0x63, time 1280314986
ber_get_next
tls_read: want=3D5 error=3DUnknown error
ldap_read: want=3D8 error=3DUnknown error
daemon: activity on 1 descriptor
daemon: waked
daemon: WSselect: listen=3D2 active_threads=3D0 tvp=3DNULL
daemon: WSselect: listen=3D3 active_threads=3D0 tvp=3DNULL
daemon: WSselect: listen=3D4 active_threads=3D0 tvp=3DNULL
=3D> access_allowed: delete access to "cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" "children" reques=
ted
<=3D root access granted
=3D> access_allowed: delete access granted by manage(=3Dmwrscxd)
=3D> access_allowed: delete access to "cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" "entry" requested
<=3D root access granted
=3D> access_allowed: delete access granted by manage(=3Dmwrscxd)
=3D> hdb_dn2id_delete 0xc4b: "cn=3Dtest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com"
<=3D hdb_dn2id_delete 0xc4b: 0
=3D> index_entry_del( 3147, "cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" )
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [aec1526a]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [78d8fcbf]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [27382a68]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [ce175d82]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [2230817c]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [815b06f7]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [8b4384f1]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [600c0260]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [58802faf]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [547b3983]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [9821f6f6]
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [0096defd]
conn=3D1000 op=3D9271 do_search
ber_scanf fmt ({miiiib) ber:
ber_dump: buf=3D015AAF30 ptr=3D015AAF34 end=3D015AAFA5 len=3D113
=A0=A00000: =A063 6f 04 4e 63 6e 3d 54 =A065 73 74 33 36 37 2c 63 =A0 co.Nc=
n=3DTest367,c
=A0=A00010: =A06e 3d 54 65 73 74 33 36 =A037 2c 63 6e 3d 73 6f 61 =A0 n=3DT=
est367,cn=3Dsoa
=A0=A00020: =A070 20 6e 6f 64 65 73 2c =A06f 3d 73 79 73 74 65 6d =A0 p nod=
es,o=3Dsystem
=A0=A00030: =A02c 63 6e 3d 63 6f 72 64 =A079 73 2c 63 6e 3d 74 32 =A0 ,cn=
=3Dcordys,cn=3Dt2
=A0=A00040: =A037 34 2c 6f 3d 76 61 6e =A065 6e 62 75 72 67 2e 63 =A0 74,o=
=3Dvanenburg.c
=A0=A00050: =A06f 6d 0a 01 00 0a 01 00 =A002 02 07 d0 02 01 00 01 =A0 om...=
...........
=A0=A00060: =A001 00 87 0b 6f 62 6a 65 =A063 74 63 6c 61 73 73 30 =A0 ....o=
bjectclass0
=A0=A00070: =A000 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 .
>>> dnPrettyNormal: <cn=3DTest367,cn=3DTest367,cn=3Dsoap nodes,o=3Dsystem,c=
n=3Dcordys,cn=3Dt274,o=3Dvanenburg.com>
=3D> ldap_bv2dn(cn=3DTest367,cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com,0)
<=3D ldap_bv2dn(cn=3DTest367,cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com)=3D0
=3D> ldap_dn2bv(272)
<=3D ldap_dn2bv(cn=3DTest367,cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com)=3D0
=3D> ldap_dn2bv(272)
<=3D ldap_dn2bv(cn=3Dtest367,cn=3Dtest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com)=3D0
<<< dnPrettyNormal: <cn=3DTest367,cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com>,
<cn=3Dtest367,cn=3Dtest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com>
SRCH "cn=3DTest367,cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" 0 0 =A0 =A02000 0=
 0
begin get_filter
PRESENT
ber_scanf fmt (m) ber:
ber_dump: buf=3D015AAF30 ptr=3D015AAF96 end=3D015AAFA5 len=3D15
=A0=A00000: =A087 0b 6f 62 6a 65 63 74 =A063 6c 61 73 73 30 00 =A0 =A0 =A0.=
.objectclass0.
end get_filter 0
=A0=A0 =A0filter: (objectClass=3D*)
ber_scanf fmt ({M}}) ber:
ber_dump: buf=3D015AAF30 ptr=3D015AAFA3 end=3D015AAFA5 len=3D2
=A0=A00000: =A000 00 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0..
=A0=A0 =A0attrs:
conn=3D1000 op=3D9271 SRCH base=3D"cn=3DTest367,cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" scope=3D0 deref=
=3D0
filter=3D"(objectClass=3D*)"
=3D> hdb_search
bdb_dn2entry("cn=3Dtest367,cn=3Dtest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com")
=3D> hdb_dn2id("cn=3Dtest367,cn=3Dtest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com")
<=3D key_change 0
=3D> key_change(DELETE,c4b)
bdb_idl_delete_key: c4b [f612c92d]
<=3D key_change 0
<=3D index_entry_del( 3147, "cn=3DTest367,cn=3Dsoap
nodes,o=3Dsystem,cn=3Dcordys,cn=3Dt274,o=3Dvanenburg.com" ) success
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
Please help.
Thanks and regards,

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


On Wed, Jul 28, 2010 at 12:49 AM, Quanah Gibson-Mount <quanah@zimbra.com> w=
rote:
>
> --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 :: =A0the leader in open source messaging and collaboration