[Bug nptl/19004] tst-robust8 fails intermittently on x86_64

["paulo.cesar.pereira.de.andrade at gmail dot com" <sourceware-bugzilla at sourceware dot org>]

https://sourceware.org/bugzilla/show_bug.cgi?id=19004

--- Comment #4 from Paulo Andrade <paulo.cesar.pereira.de.andrade at gmail dot com> ---
Created attachment 8925
  --> https://sourceware.org/bugzilla/attachment.cgi?id=8925&action=edit
robust_test2.c

  While it is very easy to reproduce in the command line, if
using stap it may take quite some time to trigger the (apparent)
race.

  Sample systemtap script output when a dead lock happens:

[29352] > syscall.wait4(upid=0x7562 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30050]  signal.send SIGCHLD to 29352
[30050] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7562
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30051] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30051] < syscall.set_robust_list() return=0x0
[29352]  signal.send SIGTERM to 30051
[30051] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[30051]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[29352] > syscall.wait4(upid=0x7563 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30051]  signal.send SIGCHLD to 29352
[30051] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7563
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30052] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30052] < syscall.set_robust_list() return=0x0
[29352]  signal.send SIGTERM to 30052
[30052] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[30052]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[29352] > syscall.wait4(upid=0x7564 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30052]  signal.send SIGCHLD to 29352
[30052] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7564
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30053] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30053] < syscall.set_robust_list() return=0x0
[29352]  signal.send SIGTERM to 30053
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[30053] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[30053]  do_exit(code=0xf)
[29352] > syscall.wait4(upid=0x7565 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30053]  signal.send SIGCHLD to 29352
[30053] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7565
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] < 0x400fed() return=0x0
[30054] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30054] < syscall.set_robust_list() return=0x0
[29352] < 0x400fed() return=0x0
[30054] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352]  signal.send SIGTERM to 30054
[30054]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[29352] > syscall.wait4(upid=0x7566 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30054]  signal.send SIGCHLD to 29352
[30054] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7566
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30055] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30055] < syscall.set_robust_list() return=0x0
[30055] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352]  signal.send SIGTERM to 30055
[30055]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[29352] > syscall.wait4(upid=0x7567 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30055]  signal.send SIGCHLD to 29352
[30055] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7567
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[30056] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30056] < syscall.set_robust_list() return=0x0
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30056] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352]  signal.send SIGTERM to 30056
[30056]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[29352] > syscall.wait4(upid=0x7568 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30056]  signal.send SIGCHLD to 29352
[30056] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7568
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[30057] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30057] < syscall.set_robust_list() return=0x0
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30057] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352]  signal.send SIGTERM to 30057
[30057]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[29352] > syscall.wait4(upid=0x7569 stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30057]  signal.send SIGCHLD to 29352
[30057] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x7569
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30058] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30058] < syscall.set_robust_list() return=0x0
[30058] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352]  signal.send SIGTERM to 30058
[30058]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] < 0x400f98() return=0x0
[29352] < 0x400f98() return=0x0
[29352] > syscall.wait4(upid=0x756a stat_addr=0x7fff9f59152c options=0x0
ru=0x0)
[29352] > schedule()
[30058]  signal.send SIGCHLD to 29352
[30058] > schedule()
[29352] < schedule() 
[29352] < syscall.wait4() return=0x756a
[30059] > syscall.set_robust_list(head=0x7fbf4b38aa20 len=0x18)
[30059] < syscall.set_robust_list() return=0x0
[29352] > schedule()
[30059] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[30059] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[30059] > syscall.futex(uaddr=0x7fbf4b3ae000 op=0x0 val=0x800072a8 utime=0x0
uaddr2=0x80 val3=0x0)
[30059] > futex_wait(uaddr=0x7fbf4b3ae000 flags=0x1 val=0x800072a8 abs_time=0x0
bitset=0xffffffff)
[30059] > futex_wait_setup(uaddr=0x7fbf4b3ae000 val=0x800072a8 flags=0x1
q=0xffff88028616bdc8 hb=0xffff88028616bd58)
[30059] < futex_wait() return=0x0
[30059] > futex_wait_queue_me(hb=0xffffc9000189c840 q=0xffff88028616bdc8
timeout=0x0)
[30059] > schedule()
Done 700 iterations
[29352] > schedule()
[29352] > pthread_mutex_unlock(mutex=0x7fbf4b3ae000)
[29352] > pthread_mutex_unlock(decr=0x1 mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_unlock_full(mutex=0x7fbf4b3ae000 decr=0x1)
[29352] > syscall.futex(uaddr=0x7fbf4b3ae000 op=0x1 val=0x1 utime=0x0
uaddr2=0x7fbf4b3ae000 val3=0x8)
[29352] < syscall.futex() return=0x1
[30059] < schedule() 
[29352] < 0x400fed() return=0x0
[29352] < 0x400fed() return=0x0
[30059] < futex_wait() 
[30059] < do_futex() return=0x0
[30059] < syscall.futex() return=0x0
[29352]  signal.send SIGTERM to 30059
[30059]  do_exit(code=0xf)
[29352] > __pthread_mutex_lock(mutex=0x7fbf4b3ae000)
[29352] > __pthread_mutex_lock_full(mutex=0x7fbf4b3ae000)
[29352] > syscall.futex(uaddr=0x7fbf4b3ae000 op=0x0 val=0x8000756b utime=0x0
uaddr2=0x80 val3=0x0)
[29352] > futex_wait(uaddr=0x7fbf4b3ae000 flags=0x1 val=0x8000756b abs_time=0x0
bitset=0xffffffff)
[29352] > futex_wait_setup(uaddr=0x7fbf4b3ae000 val=0x8000756b flags=0x1
q=0xffff88027e8cbdc8 hb=0xffff88027e8cbd58)
[29352] < futex_wait() return=0x0
[29352] > futex_wait_queue_me(hb=0xffffc9000189c840 q=0xffff88027e8cbdc8
timeout=0x0)
[29352] > schedule()
[30059]  signal.send SIGCHLD to 29352
[30059] > schedule()

  and it is dead locked at the end.

29352 is the main process and 30059 is the last forked
process. (Note that the test case only forks one child
process at a time, and tries to "race" with it to get
the mutex lock).

-- 
You are receiving this mail because:
You are on the CC list for the bug.