Re: [Valgrind-developers] Hang in err_disable4

[Paul F. <pj...@wa...>]

> Are there some other threads still alive when the process hangs 
> What are these threads doing ?

> Would be nice to re-run with more trace (-v -v -v -d -d -d --trace-sched=yes)
> and see how has last acquired the lock without releasing it 

Salut Philippe

The original testcase created 498 threads, but I reduced it to 1 to simplify matters. The problem is still there.

>From what I've seen there is just the one chiile thread waiting in the semaphore and the main thread not advancing to post the semaphore.

With just -v -v -v -d -d -d memcheck ran to completion. 

With --trace-sched=yes --trace-syscalls=yes I get the following (I've taken it from the mmap/mprotect, which I assume is the main thread setting up the memory for the child thread's stack).

The last line looks very interesting (I hadn't seen it before). It looks like there are 4 values of umtx_op that I'm not handling.



SYSCALL[40689,1](477) sys_mmap ( 0x7fffdfdfd000, 2101248, 7, 1024, 4294967295, 0x0)--40689-- di_notify_mmap-0:
--40689-- di_notify_mmap-1: 0x7fffdfdfd000-0x7fffdfffdfff rwx
--> [pre-success] Success(0x7fffdfdfd000) 
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: SYSCALL
SYSCALL[40689,1]( 74) sys_mprotect ( 0x7fffdfdfd000, 4096, 0 )[sync] --> Success(0x0) 
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: SYSCALL
SYSCALL[40689,1](455) thr_new ( 0x7ff0002d0, 104 ) --> [pre-success] Success(0x0) --40689-- SCHED[1]: releasing lock (VG_(vg_yield)) -> VgTs_Yielding
--40689-- SCHED[2]: acquired lock (thread_wrapper(starting new thread))
--40689-- SCHED[2]: entering VG_(scheduler)
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CLIENTREQ
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: SYSCALL
SYSCALL[40689,2](477) sys_mmap ( 0x0, 131072, 3, 4098, 4294967295, 0x0)--40689-- di_notify_mmap-0:
--40689-- di_notify_mmap-1: 0x4c47000-0x4ea6fff rw-
--> [pre-success] Success(0x4e87000) 
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: SYSCALL
SYSCALL[40689,2]( 4) sys_write ( 2, 0x401330, 21 ) --> [async] ... 
--40689-- SCHED[2]: releasing lock (VG_(client_syscall)[async]) -> VgTs_WaitSys
--40689-- SCHED[1]: acquired lock (VG_(vg_yield))

--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[1]: TRC: FASTMISS
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_FAST
--40689-- SCHED[1]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[1]: TRC: SYSCALL
SYSCALL[40689,1](454) sys__umtx_op ( 0x4e88000, MUTEX_WAIT, 0, 0x0, 0x0) --> [async] ... 
--40689-- SCHED[1]: releasing lock (VG_(client_syscall)[async]) -> VgTs_WaitSys
--40689-- SCHED[2]: acquired lock (VG_(client_syscall)[async])
SYSCALL[40689,2]( 4) ... [async] --> Success(0x15) 
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: SYSCALL
SYSCALL[40689,2](454) sys__umtx_op ( 0x4e88000, MUTEX_WAKE2, 0, 0x0, 0x0)[sync] --> Success(0x0) 
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_SLOW
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: CHAIN_ME_FAST
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: FASTMISS
--40689-- SCHED[2]: TRC: SYSCALL
SYSCALL[40689,2](454) sys__umtx_op ( 0x601944, 23(UNKNOWN), 0, 0x0, 0x0 )

A+
Paul