5.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 poor program performance that you suspect may be caused by futex contentions.
Simply put, futex contention occurs when multiple processes are trying to access the same lock variable at the same time. This can result in a poor performance because the lock serializes execution; one process obtains the lock while the other processes must wait for the lock variable to become available again.
The futexes.stp script probes the futex system call to show lock contention.
#! /usr/bin/env stap

# This script tries to identify contended user-space locks by hooking
# into the futex system call.

global FUTEX_WAIT = 0 /*, FUTEX_WAKE = 1 */
global FUTEX_PRIVATE_FLAG = 128 /* linux 2.6.22+ */
global FUTEX_CLOCK_REALTIME = 256 /* linux 2.6.29+ */

global lock_waits # long-lived stats on (tid,lock) blockage elapsed time
global process_names # long-lived pid-to-execname mapping

global entry_times%, uaddrs%

probe syscall.futex {
  entry_times[tid()] = gettimeofday_us()
  uaddrs[tid()] = futex_uaddr

probe syscall.futex.return {
  if (!(entry_times[tid()])) next
  elapsed = gettimeofday_us() - entry_times[tid()]
  lock_waits[pid(), uaddrs[tid()]] <<< elapsed
  delete entry_times[tid()]
  delete uaddrs[tid()]
  if (!(pid() in process_names))
    process_names[pid()] = execname()

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]),
futexes.stp needs to be manually stopped; upon exit, it prints the following information:
Example 5.19, “futexes.stp Sample Output” contains an excerpt from the output of futexes.stp upon exiting the script (after approximately 20 seconds).

Example 5.19. futexes.stp Sample Output

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