389-ds-base

#49452 deadlock in role_cache while running parallel online + offline import
Closed: wontfix by spichugi. Opened by tbordaz.

Closed: wontfix
Reopen Issue

Issue Description

The problem is a deadlock between threads handling role caches

Package Version and Platform

389-ds-base-1.3.6.1-24
RHEL

Steps to reproduce

Parallel import (on two backends). To be provided

Actual results

deadlock in role caches

Expected results

should not deadlock

Test case is looking like parallel init of two suffixes. One online init and one offline init

Offline import of M2

Nov 14 10:40:29 rhel74.example.com ns-slapd[25451]: [14/Nov/2017:10:40:29.924666571 -0500] - NOTICE - NSMMReplicationPlugin - multim aster_be_state_change - Replica dc=example,dc=com is going offline; disabling replication
Nov 14 10:40:30 rhel74.example.com ns-slapd[25451]: [14/Nov/2017:10:40:30.077186575 -0500] - INFO - dblayer_instance_start - Import

M1 is doing a online import of M2

Nov 14 10:40:30 rhel74.example.com ns-slapd[25215]: [14/Nov/2017:10:40:30.182153743 -0500] - INFO - NSMMReplicationPlugin - repl5_tot_run - Beginning total update of replica "agmt="cn=meTo_localhost:39002" (localhost:39002)".

Completing offline import on M2

Nov 14 10:40:32 rhel74.example.com ns-slapd[25451]: [14/Nov/2017:10:40:32.307240131 -0500] - INFO - import_monitor_threads - import userRoot: Workers finished; cleaning up...
Nov 14 10:40:32 rhel74.example.com ns-slapd[25451]: [14/Nov/2017:10:40:32.517097182 -0500] - INFO - import_monitor_threads - import userRoot: Workers cleaned up.
Nov 14 10:40:32 rhel74.example.com ns-slapd[25451]: [14/Nov/2017:10:40:32.524279234 -0500] - INFO - import_main_offline - import userRoot: Indexing complete.  Post-processing...
Nov 14 10:40:32 rhel74.example.com ns-slapd[25451]: [14/Nov/2017:10:40:32.578924680 -0500] - INFO - import_main_offline - import userRoot: Closing files...
Nov 14 10:40:32 rhel74.example.com ns-slapd[25451]: [14/Nov/2017:10:40:32.640592860 -0500] - INFO - import_main_offline - import userRoot: Import complete.  Processed 10 entries in 2 seconds. (5.00 entries/sec)

Completing online import on M1

Nov 14 10:40:32 rhel74.example.com ns-slapd[25215]: [14/Nov/2017:10:40:32.819245018 -0500] - INFO - NSMMReplicationPlugin - repl5_tot_run - Finished total update of replica "agmt="cn=meTo_localhost:39002" (localhost:39002)". Sent 9 entries.

Metadata Update from @tbordaz:
- Custom field component adjusted to None
- Custom field origin adjusted to None
- Custom field reviewstatus adjusted to None
- Custom field type adjusted to None
- Custom field version adjusted to None

Deadlocking threads are

Thread 9 is doing online import and acquire the global_lock. It is waiting for thread 3 to complete... but this one is waiting.

Thread 9 (Thread 0x7f85814c0700 (LWP 24145)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f859e600200 in PR_WaitCondVar (cvar=cvar@entry=0x55b7d31e1940, timeout=4294967295) at ../../../nspr/pr/src/pthreads/ptsynch.c:396
#2  0x00007f85a02c26d8 in slapi_wait_condvar (cvar=0x55b7d31e1940, timeout=timeout@entry=0x0) at ldap/servers/slapd/slapi2nspr.c:150
#3  0x00007f8595eec4b7 in roles_cache_create_suffix (sdn=sdn@entry=0x55b7d2942790) at ldap/servers/plugins/roles/roles_cache.c:362
#4  0x00007f8595eec849 in roles_cache_trigger_update_suffix (handle=<optimized out>, be_name=0x55b7d2a78a70 "groups", old_be_state=<optimized out>, new_be_state=<optimized out>) at ldap/servers/plugins/roles/roles_cache.c:467
#5  0x00007f85a0288b0e in mtn_be_state_change (be_name=0x55b7d2a78a70 "groups", old_state=old_state@entry=1, new_state=new_state@entry=2) at ldap/servers/slapd/mapping_tree.c:209
#6  0x00007f85a028c15d in mtn_internal_be_set_state (be=be@entry=0x55b7d286e970, state=state@entry=2) at ldap/servers/slapd/mapping_tree.c:3668
#7  0x00007f85a028c25e in slapi_mtn_be_disable (be=0x55b7d286e970) at ldap/servers/slapd/mapping_tree.c:3706
#8  0x00007f859358567a in bulk_import_start (pb=0x7f85814bfa50) at ldap/servers/slapd/back-ldbm/import-threads.c:3097
#9  ldbm_back_wire_import (pb=0x7f85814bfa50) at ldap/servers/slapd/back-ldbm/import-threads.c:3421
#10 0x00007f85a024e491 in process_bulk_import_op (pb=pb@entry=0x7f85814bfa50, state=state@entry=1, e=e@entry=0x0) at ldap/servers/slapd/bulk_import.c:140
#11 0x00007f85a024e66c in slapi_start_bulk_import (pb=pb@entry=0x7f85814bfa50) at ldap/servers/slapd/bulk_import.c:47
#12 0x00007f859245461f in multimaster_extop_StartNSDS50ReplicationRequest (pb=0x7f85814bfa50) at ldap/servers/plugins/replication/repl_extop.c:965
#13 0x000055b7d057e7f1 in do_extended (pb=0x7f85814bfa50) at ldap/servers/slapd/extendop.c:348
#14 0x000055b7d0577988 in connection_threadmain () at ldap/servers/slapd/connection.c:688
#15 0x00007f859e6059bb in _pt_root (arg=0x55b7d26bb060) at ../../../nspr/pr/src/pthreads/ptthread.c:216
#16 0x00007f859dfa5e25 in start_thread (arg=0x7f85814c0700) at pthread_create.c:308
#17 0x00007f859d88734d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Thread 3 is waiting on 'change_lock' lock (TBC). So far I have not found a lock leak or who can be the owner of the lock (thread 9 ?)

Thread 3 (Thread 0x7f85772a6700 (LWP 24362)):
#0  __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007f859dfa7e01 in _L_lock_1022 () from /lib64/libpthread.so.0
#2  0x00007f859dfa7da2 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x55b7d3144680) at ../nptl/pthread_mutex_lock.c:134
#3  0x00007f859e5ffe49 in PR_Lock (lock=0x55b7d3144680) at ../../../nspr/pr/src/pthreads/ptsynch.c:177
#4  0x00007f85a02c262a in slapi_lock_mutex (mutex=<optimized out>) at ldap/servers/slapd/slapi2nspr.c:72
#5  0x00007f8595eee1d0 in roles_cache_wait_on_change (arg=0x55b7d2d6c280) at ldap/servers/plugins/roles/roles_cache.c:382
#6  0x00007f859e6059bb in _pt_root (arg=0x55b7d2d6a640) at ../../../nspr/pr/src/pthreads/ptthread.c:216
#7  0x00007f859dfa5e25 in start_thread (arg=0x7f85772a6700) at pthread_create.c:308
#8  0x00007f859d88734d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Thread 4 looks victim of Thread 9 (global lock) but so far there is no evidence that it contributes to the deadlock

Thread 4 (Thread 0x7f8578aa9700 (LWP 24337)):
#0  pthread_rwlock_wrlock () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_rwlock_wrlock.S:85
#1  0x00007f85a02c27ba in slapi_rwlock_wrlock (rwlock=<optimized out>) at ldap/servers/slapd/slapi2nspr.c:238
#2  0x00007f8595eec6dc in roles_cache_trigger_update_suffix (handle=<optimized out>, be_name=0x55b7d2a7a888 "people", old_be_state=<optimized out>, new_be_state=1) at ldap/servers/plugins/roles/roles_cache.c:436
#3  0x00007f85a0288b0e in mtn_be_state_change (be_name=0x55b7d2a7a888 "people", old_state=old_state@entry=2, new_state=new_state@entry=1) at ldap/servers/slapd/mapping_tree.c:209
#4  0x00007f85a028c15d in mtn_internal_be_set_state (be=0x55b7d286c9c0, state=state@entry=1) at ldap/servers/slapd/mapping_tree.c:3668
#5  0x00007f85a028c27a in slapi_mtn_be_enable (be=<optimized out>) at ldap/servers/slapd/mapping_tree.c:3718
#6  0x00007f859357ab1c in import_all_done (job=0x55b7d312a420, ret=ret@entry=0) at ldap/servers/slapd/back-ldbm/import.c:1180
#7  0x00007f859357c92a in import_main_offline (arg=<optimized out>) at ldap/servers/slapd/back-ldbm/import.c:1603
#8  0x00007f859e6059bb in _pt_root (arg=0x55b7d26bbde0) at ../../../nspr/pr/src/pthreads/ptthread.c:216
#9  0x00007f859dfa5e25 in start_thread (arg=0x7f8578aa9700) at pthread_create.c:308
#10 0x00007f859d88734d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Metadata Update from @mreynolds:
- Issue set to the milestone: 1.4 backlog

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/2511

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
- Issue status updated to: Closed (was: Open)
Metadata
None
None
None
None
None
None
None
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.