[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: pls help: "Operations error" from ldapdelete (ITS#29)



Sent directly to me...

-------- Original Message --------
Subject: Re: pls help: "Operations error" from ldapdelete (ITS#29)
Date: Tue, 26 Jan 1999 01:10:44 +0800 (EAT)
From: "S.T. Wong" <st@hp735c.csc.cuhk.edu.hk>
To: Kurt@openldap.org (Kurt D. Zeilenga)

hi,

> >I tried OPENLDAP_REL_ENG_1_1 but the problem ("Operation error" on ldapdelete)
> >still occurred.  When the first operation after daemon start up is ldapdelete,
> >the daemon dies with segmentation fault :
> >
> ># /usr/local/openldap/libexec/slapd -f /usr/local/openldap/etc/cu.conf -d 1 -d 2
> >slapd 1.1.4-Engineering (Sat Jan 23 12:01:14 HKT 1999)
> 
> I'll try to did through your dog when I get chance.... however, would
> be easier with args logging (-d 4) in addition to trace (-d 1).

I tried several times with -d 4.  Sometimes I got segmentation fault and 
sometimes operation error, when I issue ldapdelete at the first command after
slapd started up:

-------------------------- Segmentation Fault -------------------------------
slapd 1.1.4-Engineering (Sat Jan 23 12:01:14 HKT 1999)
        root@spsdev2.csc.cuhk.edu.hk:/usr/local/src/test/ldap/servers/slapd
slapd starting
do_bind
do_bind: version 2 dn (cn=root,dc=cuhk,dc=edu,dc=hk) method 128
==> ldbm_back_bind: dn: cn=root,dc=cuhk,dc=edu,dc=hk
dn2entry_r: dn: "cn=root,dc=cuhk,dc=edu,dc=hk"
=> dn2id( "cn=root,dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 0)
<= dn2id NOID
dn2entry_r: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
<= dn2id 14226
=> id2entry_r( 14226 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2entry.gdbm", 2, 600 )ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 1)
=> str2entry
<= str2entry 0xa084a8
entry_rdwr_rlock: ID: 14226
<= id2entry_r( 14226 ) (disk)
====> cache_return_entry_r
entry_rdwr_runlock: ID: 14226
send_ldap_result 0::
do_delete
do_delete: dn (uid=1002,dc=cuhk,dc=edu,dc=hk)
==> ldbm_back_delete: uid=1002,dc=cuhk,dc=edu,dc=hk
dn2entry_w: dn: "uid=1002,dc=cuhk,dc=edu,dc=hk"
=> dn2id( "uid=1002,dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
<= dn2id 5271
=> id2entry_w( 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2entry.gdbm", 2, 600 )
<= ldbm_cache_open (cache 1)
=> str2entry
<= str2entry 0x6b8e0
entry_rdwr_wlock: ID: 5271
<= id2entry_w( 5271 ) (disk)
rdwr_Xchk: readers_reading: 0 writer_writing: 1
=> has_children( 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 2)
<= has_children 0
rdwr_Xchk: readers_reading: 0 writer_writing: 1
dn2entry_w: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
====> cache_find_entry_dn2id: found dn: DC=CUHK,DC=EDU,DC=HK
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
<= dn2id 14226 (in cache)
=> id2entry_w( 14226 )
====> cache_find_entry_dn2id: found id: 14226 rw: 1
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
entry_rdwr_wlock: ID: 14226
<= id2entry_w 0xa084a8 (cache)
=> id2children_remove( 14226, 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
<= ldbm_cache_open (cache 2)
<= id2children_remove 0
=> dn2id_delete( "1002, dc=cuhk, dc=edu, dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
Segmentation Fault - core dumped

----------------------------- Operations Error ----------------------------
# ./slapd -f ../etc/cu.conf -d 1 -d 4
slapd 1.1.4-Engineering (Sat Jan 23 12:01:14 HKT 1999)
        root@spsdev2.csc.cuhk.edu.hk:/usr/local/src/test/ldap/servers/slapd
slapd starting
do_bind
do_bind: version 2 dn (cn=root,dc=cuhk,dc=edu,dc=hk) method 128
==> ldbm_back_bind: dn: cn=root,dc=cuhk,dc=edu,dc=hk
dn2entry_r: dn: "cn=root,dc=cuhk,dc=edu,dc=hk"
=> dn2id( "cn=root,dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 0)
<= dn2id NOID
dn2entry_r: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
<= dn2id 14226
=> id2entry_r( 14226 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2entry.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 1)
=> str2entry
<= str2entry 0xa084a8
entry_rdwr_rlock: ID: 14226
<= id2entry_r( 14226 ) (disk)
====> cache_return_entry_r
entry_rdwr_runlock: ID: 14226
send_ldap_result 0::
do_delete
do_delete: dn (uid=1002,dc=cuhk,dc=edu,dc=hk)
==> ldbm_back_delete: uid=1002,dc=cuhk,dc=edu,dc=hk
dn2entry_w: dn: "uid=1002,dc=cuhk,dc=edu,dc=hk"
=> dn2id( "uid=1002,dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
<= dn2id 5271
=> id2entry_w( 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2entry.gdbm", 2, 600 )
<= ldbm_cache_open (cache 1)
=> str2entry
<= str2entry 0xa08700
entry_rdwr_wlock: ID: 5271
<= id2entry_w( 5271 ) (disk)
rdwr_Xchk: readers_reading: 0 writer_writing: 1
=> has_children( 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 2)
<= has_children 0
rdwr_Xchk: readers_reading: 0 writer_writing: 1
dn2entry_w: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
====> cache_find_entry_dn2id: found dn: DC=CUHK,DC=EDU,DC=HK
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
<= dn2id 14226 (in cache)
=> id2entry_w( 14226 )
====> cache_find_entry_dn2id: found id: 14226 rw: 1
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
entry_rdwr_wlock: ID: 14226
<= id2entry_w 0xa084a8 (cache)
=> id2children_remove( 14226, 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
<= ldbm_cache_open (cache 2)
<= id2children_remove -1 (idl_delete)
<=- ldbm_back_delete: operations error uid=1002,dc=cuhk,dc=edu,dc=hk
send_ldap_result 1::
====> cache_return_entry_w
entry_rdwr_wunlock: ID: 14226
do_unbind
ber_get_next on fd 5 failed errno 0 (Error 0)
*** got 0 of 0 so far
====> cache_return_entry_w
entry_rdwr_wunlock: ID: 5271
------------------------------ cut here ----------------------------------


> >Segmentation Fault - core dumped
> 
> A debugger backtrace ('bt'/'where') are also very useful.

I then tried to get backtrace for ldapdelete, again, there're segmentation
fault and operation errors.  Is that sufficient ?

----------------------------- Operations Error ----------------------------
(gdb) file slapd
Load new symbol table from "slapd"? (y or n) y
Reading symbols from slapd...done.
(gdb) set args -f ../etc/cu.conf -d 1 -d 4
(gdb) run
Starting program: /disks/openldap/libexec/slapd -f ../etc/cu.conf -d 1 -d 4
[New LWP    2        ]
[New LWP    3        ]
slapd 1.1.4-Engineering (Sat Jan 23 12:01:14 HKT 1999)
root@spsdev2.csc.cuhk.edu.hk:/usr/local/src/test/ldap/servers/slapd
slapd starting
[New LWP    4        ]
do_bind
do_bind: version 2 dn (cn=root,dc=cuhk,dc=edu,dc=hk) method 128
==> ldbm_back_bind: dn: cn=root,dc=cuhk,dc=edu,dc=hk
dn2entry_r: dn: "cn=root,dc=cuhk,dc=edu,dc=hk"
=> dn2id( "cn=root,dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
[New LWP    5        ]
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 0)
<= dn2id NOID
dn2entry_r: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
<= dn2id 14226
=> id2entry_r( 14226 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2entry.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 1)
=> str2entry
<= str2entry 0xa084a8
entry_rdwr_rlock: ID: 14226
<= id2entry_r( 14226 ) (disk)
====> cache_return_entry_r
entry_rdwr_runlock: ID: 14226
send_ldap_result 0::
do_delete
do_delete: dn (uid=1002,dc=cuhk,dc=edu,dc=hk)
==> ldbm_back_delete: uid=1002,dc=cuhk,dc=edu,dc=hk
dn2entry_w: dn: "uid=1002,dc=cuhk,dc=edu,dc=hk"
=> dn2id( "uid=1002,dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
<= dn2id 5271
=> id2entry_w( 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2entry.gdbm", 2, 600 )
<= ldbm_cache_open (cache 1)
=> str2entry
<= str2entry 0xa08790
entry_rdwr_wlock: ID: 5271
<= id2entry_w( 5271 ) (disk)
rdwr_Xchk: readers_reading: 0 writer_writing: 1
=> has_children( 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 2)
<= has_children 0
rdwr_Xchk: readers_reading: 0 writer_writing: 1
dn2entry_w: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
====> cache_find_entry_dn2id: found dn: DC=CUHK,DC=EDU,DC=HK
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
<= dn2id 14226 (in cache)
=> id2entry_w( 14226 )
====> cache_find_entry_dn2id: found id: 14226 rw: 1
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
entry_rdwr_wlock: ID: 14226
<= id2entry_w 0xa084a8 (cache)
=> id2children_remove( 14226, 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
<= ldbm_cache_open (cache 2)
<= id2children_remove -1 (idl_delete)
<=- ldbm_back_delete: operations error uid=1002,dc=cuhk,dc=edu,dc=hk
send_ldap_result 1::
====> cache_return_entry_w
entry_rdwr_wunlock: ID: 14226
do_unbind
ber_get_next on fd 8 failed errno 0 (Error 0)
*** got 0 of 0 so far

Program received signal SIGLWP, Signal LWP.
[Switching to LWP    4        ]

Program received signal SIGLWP, Signal LWP.
0xdf5f98a8 in _lwp_mutex_unlock ()
(gdb)
(gdb) bt
#0  0xdf5f98a8 in _lwp_mutex_unlock ()
#1  0xdf539958 in _sched_unlock ()
#2  0xdf538938 in _mutex_adaptive_unlock ()
#3  0xdf538678 in _mutex_wakeup ()
#4  0xdf545294 in __wrds ()
#5  0xdf6463cc in _rmutex_unlock ()
#6  0xdf623550 in _fprintf ()
#7  0x1d26c in entry_rdwr_unlock (e=0xa084a8, rw=1) at entry.c:266
#8  0x29d4c in cache_return_entry_rw (cache=0x606f8, e=0xa084a8, rw=1)
	at cache.c:79
	#9  0x29d90 in cache_return_entry_w (cache=0x606f8, e=0xa084a8) at cache.c:92
	#10 0x2b7b4 in ldbm_back_delete (be=0x60210, conn=0x687d8, op=0xa08538,
		dn=0x6ba00 "uid=1002,dc=cuhk,dc=edu,dc=hk") at delete.c:142
		#11 0x21b34 in do_delete (conn=0x687d8, op=0xa08538) at delete.c:77
		#12 0x195ac in connection_operation (arg_v=0x61ea8) at connection.c:58
(gdb)
---------------------------- Segmentation Fault --------------------------------
(gdb) set args -f ../etc/cu.conf -d 1 -d 4
(gdb) run
Starting program: /disks/openldap/libexec/slapd -f ../etc/cu.conf -d 1 -d 4
[New LWP    2        ]
[New LWP    3        ]
slapd 1.1.4-Engineering (Sat Jan 23 12:01:14 HKT 1999)
        root@spsdev2.csc.cuhk.edu.hk:/usr/local/src/test/ldap/servers/slapd
slapd starting
[New LWP    4        ]
do_bind
do_bind: version 2 dn (cn=root,dc=cuhk,dc=edu,dc=hk) method 128
==> ldbm_back_bind: dn: cn=root,dc=cuhk,dc=edu,dc=hk
dn2entry_r: dn: "cn=root,dc=cuhk,dc=edu,dc=hk"
[=> dn2id( "Ncn=root,dc=cuhk,dc=edu,dc=hk" )
ew L=> ldbm_cache_open( "WP  /usr/local/openldap/var/db/dn2id.gdbm  5 ", 2  , 60
0  )
    ]
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 0)
<= dn2id NOID
dn2entry_r: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
<= dn2id 14226
=> id2entry_r( 14226 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2entry.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 1)
=> str2entry
<= str2entry 0xa084a8
entry_rdwr_rlock: ID: 14226
<= id2entry_r( 14226 ) (disk)
====> cache_return_entry_r
entry_rdwr_runlock: ID: 14226
send_ldap_result 0::
do_delete
do_delete: dn (uid=1002,dc=cuhk,dc=edu,dc=hk)
==> ldbm_back_delete: uid=1002,dc=cuhk,dc=edu,dc=hk
dn2entry_w: dn: "uid=1002,dc=cuhk,dc=edu,dc=hk"
=> dn2id( "uid=1002,dc=cuhk,dc=edu,dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)
[<= dn2id 5271New
 LW=> id2entry_P  w( 5271   )
6 => ldbm_cache_open( "  /usr/local/openldap/var/db/id2entry.gdbm   ", 2 ,  600]
 )
<= ldbm_cache_open (cache 1)
=> str2entry
<= str2entry 0x6b8e0
entry_rdwr_wlock: ID: 5271
<= id2entry_w( 5271 ) (disk)
rdwr_Xchk: readers_reading: 0 writer_writing: 1
=> has_children( 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
ldbm_cache_open (blksize 8192) (maxids 2046) (maxindirect 2)
<= ldbm_cache_open (opened 2)
<= has_children 0
rdwr_Xchk: readers_reading: 0 writer_writing: 1
dn2entry_w: dn: "dc=cuhk,dc=edu,dc=hk"
=> dn2id( "dc=cuhk,dc=edu,dc=hk" )
====> cache_find_entry_dn2id: found dn: DC=CUHK,DC=EDU,DC=HK
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
<= dn2id 14226 (in cache)
=> id2entry_w( 14226 )
====> cache_find_entry_dn2id: found id: 14226 rw: 1
entry_rdwr_rlock: ID: 14226
entry_rdwr_runlock: ID: 14226
entry_rdwr_wlock: ID: 14226
<= id2entry_w 0xa084a8 (cache)
=> id2children_remove( 14226, 5271 )
=> ldbm_cache_open( "/usr/local/openldap/var/db/id2children.gdbm", 2, 600 )
<= ldbm_cache_open (cache 2)
<= id2children_remove 0
=> dn2id_delete( "1002, dc=cuhk, dc=edu, dc=hk" )
=> ldbm_cache_open( "/usr/local/openldap/var/db/dn2id.gdbm", 2, 600 )
<= ldbm_cache_open (cache 0)

Program received signal SIGSEGV, Segmentation fault.
0x41968 in _gdbm_get_bucket ()
(gdb) bt
#0  0x41968 in _gdbm_get_bucket ()
#1  0x42bb8 in _gdbm_findkey ()
#2  0x40ec0 in gdbm_delete ()
#3  0x3579c in ldbm_delete (ldbm=0x6c388, key={
	  dptr = 0x6baa0 "1002,DC=CUHK,DC=EDU,DC=HK", dsize = 26}) at ldbm.c:356
#4  0x2b28c in ldbm_cache_delete (db=0x60738, key={
      dptr = 0x6baa0 "1002,DC=CUHK,DC=EDU,DC=HK", dsize = 26}) at dbcache.c:261
#5  0x2bde8 in dn2id_delete (be=0x60210,
	  dn=0x6baa0 "1002,DC=CUHK,DC=EDU,DC=HK") at dn2id.c:141
#6  0x2b6c8 in ldbm_back_delete (be=0x60210, conn=0x687d8, op=0xa08538,
	  dn=0x6ba00 "1002,dc=cuhk,dc=edu,dc=hk") at delete.c:117
#7  0x21b34 in do_delete (conn=0x687d8, op=0xa08538) at delete.c:77
#8  0x195ac in connection_operation (arg_v=0x61ea8) at connection.c:58
(gdb)
-------------------------------- cut here ----------------------------------

> >Then I tried the 1_2 branch, but compilation fails on error 
> >(Solaris 2.6 + gdbm):
> >...
> >gcc -g -O2 -I../../include -I../../include   -I/usr/local/include -DHAVE_CONFIG_H   -c  bind.c
> 
> fixed.  try a 'cvs update'

Thanks, but I got another compilation error when linking libbackends.a:

Undefined                       first referenced
 symbol                             in file
dbEnvInit_mutex                     libbackends.a(ldbminit.o)
ld: fatal: Symbol referencing errors. No output written to slapd
*** Error code 1
make: Fatal error: Command failed for target `slapd'
Current working directory /usr/local/src/test/ldap/servers/slapd
*** Error code 1


Any advice ?  Thanks a lot!

Best Regards,
ST