389-ds-base

#48287 Double free while adding entries (1.2.11 only)
Closed: wontfix Opened by tbordaz.

Closed: wontfix
Reopen Issue

This problem was found while investigating https://fedorahosted.org/freeipa/ticket/5235
It was reproduced on RHEL 6.7 (389-ds-base-1.2.11.15-60.el6.x86_64)

The test case to reproduce is:
- install IPA master
- install IPA replica
- (enable core dump: yum install abrt, sysctl -w fs.suid_dumpable=1, 'ulimit -c unlimited' in /etc/sysconfig/dirsrv)
- iterate the provided script 'steps.sh'
- the master replica will crash

The crash is not systematic. On my VMs it happens once in ~[20,100] 'steps.sh'

Sometime the test case ends in breaking IPA topology (ipa user-add fails, or total init fails) without crash. It requires to reinstall the topology.

Each time (crash or IPA topology break) the following messages are logged:

[23/Sep/2015:15:31:25 +0200] NSMMReplicationPlugin - changelog program - _cl5WriteOperationTxn: retry (49) the transaction (csn=5602a9a9000000040000) failed (rc=-30994 (DB_LOCK_DEADLOCK: Locker killed to resolve a deadlock))
[23/Sep/2015:15:31:25 +0200] NSMMReplicationPlugin - changelog program - _cl5WriteOperationTxn: failed to write entry with csn (5602a9a9000000040000); db error - -30994 DB_LOCK_DEADLOCK: Locker killed to resolve a deadlock
[23/Sep/2015:15:31:25 +0200] NSMMReplicationPlugin - write_changelog_and_ruv: can't add a change for uid=user_1809_2,cn=users,cn=accounts,dc=abc,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com (uniqid: 51b06805-61f711e5-a12e9486-e75d4fed, optype: 16) to changelog csn 5602a9a9000000040000

attachment
steps.sh

DS aborts with this stack

{{{

0 0x00007f90f5e6e625 in raise (sig=) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64

1 0x00007f90f5e6fe05 in abort () at abort.c:92

2 0x00007f90f5eac537 in __libc_message (do_abort=2, fmt=0x7f90f5f94900 " glibc detected *** %s: %s: 0x%s \n")

at ../sysdeps/unix/sysv/linux/libc_fatal.c:198

3 0x00007f90f5eb1f4e in malloc_printerr (action=3, str=0x7f90f5f929ee "free(): invalid pointer", ptr=,

ar_ptr=<value optimized out>) at malloc.c:6350

4 0x00007f90f5eb4c5d in _int_free (av=0x7f90f61cbe80, p=0x7f90d82185c0, have_lock=0) at malloc.c:4836

5 0x00007f90f83ca396 in slapi_ch_free (ptr=0x7f90d8036f70) at ldap/servers/slapd/ch_malloc.c:363

6 0x00007f90f83c4713 in attr_done (a=0x7f90d8036f70) at ldap/servers/slapd/attr.c:379

7 0x00007f90f83c478b in slapi_attr_free (ppa=) at ldap/servers/slapd/attr.c:367

8 0x00007f90f83c54ec in attrlist_free (alist=) at ldap/servers/slapd/attrlist.c:53

9 0x00007f90f83da610 in slapi_entry_free (e=0x7f90d8144ca0) at ldap/servers/slapd/entry.c:1974

10 0x00007f90edbf99d8 in backentry_free (bep=0x7f90c4be1e68) at ldap/servers/slapd/back-ldbm/backentry.c:57

11 0x00007f90edbfa57c in entrycache_add_int (cache=, e=, state=0,

alt=<value optimized out>) at ldap/servers/slapd/back-ldbm/cache.c:1448

12 0x00007f90edbfba5a in cache_add (cache=0x199e3b8, ptr=0x7f90a890e670, alt=0x7f90c4be1f68)

at ldap/servers/slapd/back-ldbm/cache.c:1476

13 0x00007f90edc0c2c0 in id2entry (be=0x199cf70, id=1757, txn=0x7f90c4be2040, err=)

at ldap/servers/slapd/back-ldbm/id2entry.c:455

14 0x00007f90edc42203 in ldbm_back_next_search_entry_ext (pb=0x7f90a84c4d00, use_extension=0)

at ldap/servers/slapd/back-ldbm/ldbm_search.c:1622

15 0x00007f90f840a061 in iterate (pb=0x7f90a84c4d00, be=, pnentries=0x7f90c4be6234, pagesize=-1,

pr_statp=0x7f90c4be6228, send_result=1) at ldap/servers/slapd/opshared.c:1296

16 0x00007f90f840a577 in send_results_ext (pb=0x7f90a84c4d00, nentries=0x7f90c4be6234, pagesize=-1, pr_stat=0x7f90c4be6228,

send_result=1) at ldap/servers/slapd/opshared.c:1696

17 0x00007f90f840b491 in op_shared_search (pb=0x7f90a84c4d00, send_result=1) at ldap/servers/slapd/opshared.c:864

18 0x00007f90f8417dac in search_internal_callback_pb (pb=0x7f90a84c4d00, callback_data=,

prc=0x7f90f8417970 <internal_plugin_result_callback>, psec=0x7f90f84181f0 <internal_plugin_search_entry_callback>, 
prec=0x7f90f8418190 <internal_plugin_search_referral_callback>) at ldap/servers/slapd/plugin_internal_op.c:812

19 0x00007f90f8417fc8 in search_internal_pb (pb=0x7f90a84c4d00) at ldap/servers/slapd/plugin_internal_op.c:665

20 0x00007f90f056b157 in search_one_berval (baseDN=0x7f90a81f5ba0, attrName=, value=,

requiredObjectClass=<value optimized out>, target=0x7f90a8074120) at ldap/servers/plugins/uiduniq/uid.c:322

21 0x00007f90f056b3fb in search (baseDN=0x7f90a81f5ba0, attrName=0x19306e0 "ipaUniqueID", attr=0x7f90a8035f60,

values=<value optimized out>, requiredObjectClass=0x0, target=0x7f90a8074120) at ldap/servers/plugins/uiduniq/uid.c:261

22 0x00007f90f056b5f5 in searchAllSubtrees (argc=1, argv=, attrName=0x19306e0 "ipaUniqueID",

attr=0x7f90a8035f60, values=0x0, requiredObjectClass=0x0, dn=0x7f90a8074120) at ldap/servers/plugins/uiduniq/uid.c:411

23 0x00007f90f056c276 in preop_add (pb=0x2bb8fe0) at ldap/servers/plugins/uiduniq/uid.c:645

24 0x00007f90f8414b92 in plugin_call_func (list=0x1935550, operation=407, pb=0x2bb8fe0, call_one=0)

at ldap/servers/slapd/plugin.c:1453

25 0x00007f90f8414ddf in plugin_call_list (pb=0x2bb8fe0, whichfunction=407) at ldap/servers/slapd/plugin.c:1415

26 plugin_call_plugins (pb=0x2bb8fe0, whichfunction=407) at ldap/servers/slapd/plugin.c:398

27 0x00007f90f83c1c64 in op_shared_add (pb=0x2bb8fe0) at ldap/servers/slapd/add.c:669

---Type to continue, or q to quit---

28 0x00007f90f83c318d in do_add (pb=0x2bb8fe0) at ldap/servers/slapd/add.c:258

29 0x0000000000414564 in connection_dispatch_operation () at ldap/servers/slapd/connection.c:579

30 connection_threadmain () at ldap/servers/slapd/connection.c:2360

31 0x00007f90f6834a83 in _pt_root (arg=0x1d15be0) at ../../../nspr/pr/src/pthreads/ptthread.c:212

32 0x00007f90f61d7a51 in start_thread (arg=0x7f90c4bed700) at pthread_create.c:301

33 0x00007f90f5f2496d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

}}}

Ticket has been cloned to Bugzilla: https://bugzilla.redhat.com/show_bug.cgi?id=1265851

Hello Noriko,

Great finding and fix !!
ACK

Did you manage to reproduce with valgrind ?

Replying to [comment:6 tbordaz]:

Hello Noriko,

Great finding and fix !!
ACK

Did you manage to reproduce with valgrind ?

Thanks, Thierry! Actually, I could not reproduce the bug with valgrind. The issue is IPA start's timeout (I guess). DS itself has no problem to run with valgrind. But using "ipaclt start", I could not make the following KDC start successfully. I guess there's some trick to let it wait, but I gave it up there and did more research in the DS itself. I came to this conclusion in the 1.2.11 code, was to apply the change to the master, then found the same fix was there!! :)

Reviewed by Thierry (Thank you!!)

Pushed to 389-ds-base-1.2.11:
217ea08..265c6e3 389-ds-base-1.2.11 -> 389-ds-base-1.2.11
commit 265c6e399016ad4a46c8709d32367b9c30ea57cf

Metadata Update from @nhosoi:
- Issue assigned to nhosoi
- Issue set to the milestone: 1.2.11.33

389-ds-base is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in 389-ds-base's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/389ds/389-ds-base/issues/1618

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Metadata Update from @spichugi:
- Issue close_status updated to: wontfix (was: Fixed)
Metadata
None
None
None
Normal
ack
IPA
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.