Bug 19402

Created attachment 8863 [details]
Test program for shared robust mutex with asynchronous termination

I have a test program that sets up a process-shared robust mutex, and then forks a child that repeatedly locks and unlocks the mutex in a loop while the parent concurrently sends a signal to kill the child. It repeats this, forking a new child each time, until the required number of iterations complete and the program exists or the program stops making progress for some reason.

Steps to reproduce
==================
Compile and run the attached test program on a Linux system with at least two CPU cores.

e.g.
$ gcc -Wall -g  test_robust.c  -lpthread -o test_robust
$ ./test_robust
iteration 0
  C-c C-c
$

Actual results
==============
The program stalls, on my system usually after less than 200 iterations.

Expected results
================
I expect the program always to run to completion in a reasonable amount of time. The stalled state shouldn't exist because the robust mutex was either locked or unlocked at the time the child terminated, and so pthread_mutex_lock in the parent should return either EOWNERDEAD or no error, respectively.

Test platform
=============
Dual-core Intel(R) Core(TM)2 Duo CPU     P8600  @ 2.40GHz
Linux debian8 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u1 (2015-12-14) x86_64 GNU/Linux
Hosted under VMWare Fusion 4.1.4 on Mac OS X 10.6.8

Results are the same both with the stock debian jessie glibc (2.19-18+deb8) and with a glibc built on this system from git glibc sources as of commit 2cf3e1aa7477b813ca3ebb901003a7d44f970218 (2015-12-22 13:39:19 UTC).

I have seen a similar test program exhibit the same problem on bare metal Red Hat Linux systems, so I don't think it is VMWare or Debian specific.

Further details
===============

I have done a few things to investigate this further. Firstly, in the stalled state the child process is definitely terminated but the parent process is stuck in a futex system call - see example session below:

$ make test_robust
cc -Wall -g -I/home/raoul/install/include -I /usr/lib/gcc/x86_64-linux-gnu/4.9.2/include -I /usr/include -I /usr/include/x86_64-linux-gnu -L/home/raoul/install/lib -Wl,-rpath=/home/raoul/install/lib -Wl,--dynamic-linker=/home/raoul/install/lib/ld-2.22.90.so  test_robust.c  -lpthread -o test_robust
$ ./test_robust &
[1] 25446
$ iteration 0
iteration 100

$ ps
  PID TTY          TIME CMD
25144 pts/2    00:00:00 bash
25446 pts/2    00:00:00 test_robust
25549 pts/2    00:00:00 ps
$ cat /proc/$!/stack
[<ffffffff810d18cc>] futex_wait_queue_me+0xcc/0x130
[<ffffffff810d1ba2>] futex_wait+0x162/0x260
[<ffffffff8108958a>] posix_cpu_timers_exit+0x1a/0x30
[<ffffffff810d3d22>] do_futex+0xf2/0xb60
[<ffffffff810a76b2>] remove_wait_queue+0x12/0x50
[<ffffffff810694fc>] do_wait+0x11c/0x230
[<ffffffff810d47fe>] SyS_futex+0x6e/0x150
[<ffffffff81068410>] child_wait_callback+0x0/0x60
[<ffffffff81513ccd>] system_call_fast_compare_end+0x10/0x15
[<ffffffffffffffff>] 0xffffffffffffffff

Secondly, it is possible to attach gdb to the parent and inspect the state of the mutex in the stalled state, which (I think) shows the mutex is "locked" by the terminated child process:

$ gdb -p $!
GNU gdb (Debian 7.7.1+dfsg-5) 7.7.1
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 25446
Reading symbols from /home/raoul/c/test_robust...done.
Reading symbols from /home/raoul/install/lib/libpthread.so.0...done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/home/raoul/install/lib/libthread_db.so.1".
Loaded symbols for /home/raoul/install/lib/libpthread.so.0
Reading symbols from /home/raoul/install/lib/libc.so.6...done.
Loaded symbols for /home/raoul/install/lib/libc.so.6
Reading symbols from /home/raoul/install/lib/ld-2.22.90.so...done.
Loaded symbols for /home/raoul/install/lib/ld-2.22.90.so
__lll_robust_lock_wait ()
    at ../sysdeps/unix/sysv/linux/x86_64/lowlevelrobustlock.S:85
85		movl	(%rdi), %eax
(gdb) frame 3
#3  0x0000000000401190 in main (argc=1, argv=0x7ffde4bc39d8)
    at test_robust.c:137
137	      do_lock(shared);
(gdb) set print pretty
(gdb) print *shared
$1 = {
  mutex = {
    __data = {
      __lock = -2147458100, 
      __count = 1, 
      __owner = 0, 
      __nusers = 0, 
      __kind = 656, 
      __spins = 0, 
      __elision = 0, 
      __list = {
        __prev = 0x0, 
        __next = 0x0
      }
    }, 
    __size = "\314c\000\200\001", '\000' <repeats 11 times>, "\220\002", '\000' <repeats 21 times>, 
    __align = 6442476492
  }, 
  child_state = 2, 
  child_pid = 25548, 
  reclaims = 95
}
(gdb) print/x shared->mutex.__data.__lock
$2 = 0x800063cc
(gdb) print shared->mutex.__data.__lock & 0xffff
$3 = 25548
(gdb) print shared->child_pid
$4 = 25548
(gdb) quit
A debugging session is active.

	Inferior 1 [process 25446] will be detached.

Quit anyway? (y or n) y
Detaching from program: /home/raoul/c/test_robust, process 25446
$ kill %%; wait %%
[1]+  Terminated              ./test_robust


Finally, it is possible to parameterize the test program such that it
sends the child a SIGABRT instead of a SIGTERM, which causes it to
dump core. This allows us to see where the child process was executing
when it terminated. In my case, I have no corefile pattern on the
system so the same corefile gets repeatedly overwritten until the
parent stalls:

$ ulimit -c unlimited
$ ./test_robust 200 6 &
[1] 26200
$ iteration 0
iteration 100

$ gdb test_robust core
[snip]
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f52d0a23735 in __pthread_mutex_lock_full (mutex=0x7f52d0e55000)
    at ../nptl/pthread_mutex_lock.c:256
256		  oldval = LLL_ROBUST_MUTEX_LOCK (mutex, id);
(gdb) disas
Dump of assembler code for function __pthread_mutex_lock_full:
[snip]
   0x00007f52d0a23710 <+768>:	and    $0x40000000,%eax
   0x00007f52d0a23715 <+773>:	jne    0x7f52d0a237b8 <__pthread_mutex_lock_full+936>
   0x00007f52d0a2371b <+779>:	and    $0x3fffffff,%edx
   0x00007f52d0a23721 <+785>:	cmp    %edx,%ebp
   0x00007f52d0a23723 <+787>:	je     0x7f52d0a23815 <__pthread_mutex_lock_full+1029>
   0x00007f52d0a23729 <+793>:	mov    %ebp,%edi
   0x00007f52d0a2372b <+795>:	mov    %r10d,%eax
   0x00007f52d0a2372e <+798>:	mov    %r9d,%esi
   0x00007f52d0a23731 <+801>:	lock cmpxchg %edi,(%rbx)
=> 0x00007f52d0a23735 <+805>:	je     0x7f52d0a2374d <__pthread_mutex_lock_full+829>
   0x00007f52d0a23737 <+807>:	lea    (%rbx),%rdi
   0x00007f52d0a2373a <+810>:	sub    $0x80,%rsp
   0x00007f52d0a23741 <+817>:	callq  0x7f52d0a29e50 <__lll_robust_lock_wait>
[snip]
End of assembler dump.
(gdb) info reg eflags
eflags         0x246	[ PF ZF IF ]
(gdb) where
#0  0x00007f52d0a23735 in __pthread_mutex_lock_full (mutex=0x7f52d0e55000)
    at ../nptl/pthread_mutex_lock.c:256
#1  0x0000000000400e04 in run_child (shared=0x7f52d0e55000)
    at test_robust.c:62
#2  0x0000000000400f0b in do_fork (shared=0x7f52d0e55000) at test_robust.c:81
#3  0x000000000040119c in main (argc=3, argv=0x7fff630d1cd8)
    at test_robust.c:138
(gdb) frame 3
#3  0x000000000040119c in main (argc=3, argv=0x7fff630d1cd8)
    at test_robust.c:138
138	      do_fork(shared);
(gdb) set print pretty
(gdb) print *shared
$1 = {
  mutex = {
    __data = {
      __lock = 26301, 
      __count = 1, 
      __owner = 0, 
      __nusers = 0, 
      __kind = 656, 
      __spins = 0, 
      __elision = 0, 
      __list = {
        __prev = 0x0, 
        __next = 0x0
      }
    }, 
    __size = "\275f\000\000\001", '\000' <repeats 11 times>, "\220\002", '\000' <repeats 21 times>, 
    __align = 4294993597
  }, 
  child_state = 2, 
  child_pid = 26301, 
  reclaims = 89
}
(gdb) print/x shared->mutex
$2 = {
  __data = {
    __lock = 0x66bd, 
    __count = 0x1, 
    __owner = 0x0, 
    __nusers = 0x0, 
    __kind = 0x290, 
    __spins = 0x0, 
    __elision = 0x0, 
    __list = {
      __prev = 0x0, 
      __next = 0x0
    }
  }, 
  __size = {0xbd, 0x66, 0x0, 0x0, 0x1, 0x0 <repeats 11 times>, 0x90, 0x2, 
    0x0 <repeats 22 times>}, 
  __align = 0x1000066bd
}

Here is another slightly different case where the child terminated after the LLL_ROBUST_MUTEX_LOCK, but before (or during) the ENQUEUE_MUTEX:

Program terminated with signal SIGABRT, Aborted.
#0  0x00007f892a4f0777 in __pthread_mutex_lock_full (mutex=0x7f892a922000)
    at ../nptl/pthread_mutex_lock.c:272
272	      ENQUEUE_MUTEX (mutex);
(gdb) disas
[snip]
   0x00007f892a4f075f <+847>:	movl   $0x1,0x4(%rbx)
   0x00007f892a4f0766 <+854>:	mov    %fs:0x2e0,%rax
   0x00007f892a4f076f <+863>:	and    $0xfffffffffffffffe,%rax
   0x00007f892a4f0773 <+867>:	mov    %r8,-0x8(%rax)
=> 0x00007f892a4f0777 <+871>:	mov    %fs:0x2e0,%rax
   0x00007f892a4f0780 <+880>:	mov    %rax,0x20(%rbx)
[snip]


Speculation
===========
My theory is that there are at least some points in the execution of pthread_mutex_lock and/or pthread_mutex_unlock where an asynchronous termination signal can leave the mutex in a locked state which the kernel does not resolve during termination. In the example termination points above, the LLL_ROBUST_MUTEX_LOCK has completed but the mutex has not yet been added to the thread-specific robust mutex list. This kind of termination is not likely, but is possible via an external process sending a signal (as in this test) or another thread in the same program encountering a SEGV or such like.