Re: (ITS#8429) deadlock on a modification operation with replication

[hyc@symas.com]

elecharny@apache.org wrote:
> Full_Name: Emmanuel Lecharny
> Version: 2.4.44
> OS: Linux CentOS 6
> URL: ftp://ftp.openldap.org/incoming/
> Submission from: (NULL) (92.169.142.218)
>
>
> I have a server blocked on a modification operation, which can neither be
> shutdown nicely. Looking at the backtrace, I see that two threads are mutually
> blocked (thread 2 and thread 3) :

using gdb, I saw that the threads were blocked on a rmutex whose owning thread 
had already exited. The fact that the thread exited is due to the fact that a 
slapd shutdown was requested. Since the thread was gone already, there's 
nothing more we can extract from this process.

This shows that there's a bug in the accesslog overlay, where an operation may 
get interrupted without releasing the rmutex. Someone will need to track that 
down.
>
> Thread 4 (Thread 0x7f305fc97700 (LWP 28853))A%A
> #0  0x0000003a9ba0b63c in pthread_cond_wait@@GLIBC_2.3.2 () from
> /lib64/libpthread.so.0
> #1  0x00007f30a46395ab in ldap_pvt_thread_pool_destroy (tpool=0x727100,
> run_pending=1) at /home/build/sold-2.4.44.2/openldap/libraries/libldap_r/tpool.c:817
> #2  0x000000000042c619 in slapd_daemon_task (ptr=<value optimized out>) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/daemon.c:2851
> #3  0x0000003a9ba07a51 in start_thread () from /lib64/libpthread.so.0
> #4  0x0000003a9b6e896d in clone () from /lib64/libc.so.6
>
> Thread 3 (Thread 0x7f305f496700 (LWP 28854)):
> #0  0x0000003a9ba0b63c in pthread_cond_wait@@GLIBC_2.3.2 () from
> /lib64/libpthread.so.0
> #1  0x00007f30a463839b in ldap_pvt_thread_rmutex_lock (rmutex=<value optimized
> out>, owner=139845733803776) at
> /home/build/sold-2.4.44.2/openldap/libraries/libldap_r/rmutex.c:129
> #2  0x00007f30a09cf0cf in accesslog_op_mod (op=0x7f305f495450, rs=<value
> optimized out>) at /home/build/sold-2.4.44.2/openldap/servers/slapd/overlays/accesslog.c:1984
> #3  0x0000000000496dc2 in overlay_op_walk (op=0x7f305f495450, rs=0x7f305f494740,
> which=op_modify, oi=0x886a30, on=0x88ba10) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/backover.c:661
> #4  0x0000000000497873 in over_op_func (op=0x7f305f495450, rs=<value optimized
> out>, which=<value optimized out>) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/backover.c:730
> #5  0x000000000048bea6 in syncrepl_updateCookie (si=0x886650, op=0x7f305f495450,
> syncCookie=<value optimized out>) at
> /home/build/sold-2.4.44.2/enenldap/servers/slapd/syncrepl.c:3889
> #6  0x000000000048cf1b in do_syncrep2 (op=0x7f305f495450, si=0x886650) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/syncrepl.c:1187
> #7  0x00000000004932a2 in do_syncrepl (ctx=<value optimized out>, arg=0x885b50)
> at /home/build/sold-2.4.44.2/openldap/servers/slapd/syncrepl.c:1561
> #8  0x00007f30a463a058 in ldap_int_thread_pool_wrapper (xpool=0x817d80) at
> /home/build/sold-2.4.44.2/openldap/libraries/libldap_r/tpool.c:956
> #9  0x0000003a9ba07a51 in start_thread ()rfrom /lib62F2Flibpthread.so.0
> #10 0x0000003a9b6e896d in clone () from /lib64/libc.so.6
>
> Thread 2 (Thread 0x7f305ec95700 (LWP 28855)):
> #0  0x0000003a9ba0b63c in pthread_cond_wait@@GLIBC_2.3.2 () from
> /lib64/libpthread.so.0
> #1  0x00007f30a463839b in ldap_pvt_thread_rmutex_lock (rmutex=<value optimized
> out>, owner=139845725411072) at
> /home/build/sold-2.4.44.2/openldap/libraries/libldap_r/rmutex.c:129
> #2  0x00007f30a09cf0cf in accesslog_op_mod (op=0x7f3050114290, rs=<value
> optimized out>) at /home/build/sold-2.4.44.2%2pepenldap/servers/slapd/overlays/accesslog.c:1984
> #3  0x0000000000496dc2 in overlay_op_walk (op=0x7f3050114290, rs=0x7f305ec949f0,
> which=op_modify, oi=0x886a30, on=0x88ba10) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/backover.c:661
> #4  0x0000000000497873 in over_op_func (op=0x7f3050114290, rs=<value optimized
> out>, which=<value optimized out>) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/backover.c:730
> #5  0x00000000004464eb in fe_op_modify (op=0x7f3050114290, rs=0x7f305ec949f0) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/modify.c:303
> #6  0x0000000000446e16 in do_modify (op=0x7f3050114290, rs=0x7f305ec949f0) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/modify.c:177
> #7  0x000000000042ea79 in connection_operation (ctx=0x7f305ec94b70,
> arg_v=0x7f3050114290) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/connection.c:1158
> #8  0x000000000042f265 in connection_read_thread (ctx=0x7f305ec94b70,
> argv=<value optimized out>) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/connection.c:1294
> #9  0x00007f30a463a058 in ldap_int_thread_pool_wrapper (xpool=0x817d80) at
> /home/build/sold-2.4.44.2/openldap/libraries/libldap_r/tpool.c:956
> #10 0x0000003a9ba07a51 in start_thread () from /lib64/libpthread.so.0
> #11 0x0000003a9b6e896d in clone () from /lib64/libc.so.6
>
> Thread 1 (Thread 0x7f30a3565700 (LWP 28852)):
> #0  0x0000003a9ba082ad in pthread_join () from /lib64/libpthread.so.0
> #1  0x0000000000428fc9 in slapd_daemon () at
> /home/build/sold-2.4.44.2/openldap/servers/apapd/daemon.c:2932
> #2  0x0000000000415135 in main (argc=9, argv=<value optimized out>) at
> /home/build/sold-2.4.44.2/openldap/servers/slapd/main.c:1016


-- 
   -- Howard Chu
   CTO, Symas Corp.           http://www.symas.com
   Director, Highland Sun     http://highlandsun.com/hyc/
   Chief Architect, OpenLDAP  http://www.openldap.org/project/