4.4. Identifying Contended User-Space Locks This section describes how to identify contended user-space locks throughout the system within a specific time period. The ability to identify contended user-space locks can help you investigate hangs that you suspect may be caused by futex contentions. Simply put, a futex contention occurs when multiple processes are trying to access the same region of memory. In some cases, this can result in a deadlock between the processes in contention, thereby appearing as an application hang. To do this, Example 4.34, "futexes.stp" probes the futex system call. Example 4.34. futexes.stp #! /usr/bin/env stap # This script tries to identify contended user-space locks by hooking # into the futex system call. global thread_thislock # short global thread_blocktime # global FUTEX_WAIT = 0 /*, FUTEX_WAKE = 1 */ global lock_waits # long-lived stats on (tid,lock) blockage elapsed time global process_names # long-lived pid-to-execname mapping probe syscall.futex { if (op != FUTEX_WAIT) # don't care about WAKE event originator t = tid () process_names[pid()] = execname() thread_thislock[t] = USDuaddr thread_blocktime[t] = gettimeofday_us() } probe syscall.futex.return { t = tid() ts = thread_blocktime[t] if (ts) { elapsed = gettimeofday_us() - ts lock_waits[pid(), thread_thislock[t]] <<< elapsed delete thread_blocktime[t] delete thread_thislock[t] } } probe end { foreach ([pid+, lock] in lock_waits) printf ("%s[%d] lock %p contended %d times, %d avg us\n", process_names[pid], pid, lock, @count(lock_waits[pid,lock]), @avg(lock_waits[pid,lock])) } Example 4.34, "futexes.stp" needs to be manually stopped; upon exit, it prints the following information: Name and ID of the process responsible for a contention The region of memory it contested How many times the region of memory was contended Average time of contention throughout the probe Example 4.35, "Example 4.34, "futexes.stp" Sample Output" contains an excerpt from the output of Example 4.34, "futexes.stp" upon exiting the script (after approximately 20 seconds). Example 4.35. Example 4.34, "futexes.stp" Sample Output

Commands:
#! /usr/bin/env stap This script tries to identify contended user-space locks by hooking into the futex system call. global thread_thislock # short global thread_blocktime # global FUTEX_WAIT = 0 /*, FUTEX_WAKE = 1 */ global lock_waits # long-lived stats on (tid,lock) blockage elapsed time global process_names # long-lived pid-to-execname mapping probe syscall.futex { if (op != FUTEX_WAIT) next # don't care about WAKE event originator t = tid () process_names[pid()] = execname() thread_thislock[t] = USDuaddr thread_blocktime[t] = gettimeofday_us() } probe syscall.futex.return { t = tid() ts = thread_blocktime[t] if (ts) { elapsed = gettimeofday_us() - ts lock_waits[pid(), thread_thislock[t]] <<< elapsed delete thread_blocktime[t] delete thread_thislock[t] } } probe end { foreach ([pid+, lock] in lock_waits) printf ("%s[%d] lock %p contended %d times, %d avg us\n", process_names[pid], pid, lock, @count(lock_waits[pid,lock]), @avg(lock_waits[pid,lock])) }
[...] automount[2825] lock 0x00bc7784 contended 18 times, 999931 avg us synergyc[3686] lock 0x0861e96c contended 192 times, 101991 avg us synergyc[3758] lock 0x08d98744 contended 192 times, 101990 avg us synergyc[3938] lock 0x0982a8b4 contended 192 times, 101997 avg us [...]