futex contentions.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.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 {
if ((op & ~(FUTEX_PRIVATE_FLAG|FUTEX_CLOCK_REALTIME)) != FUTEX_WAIT) next
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]),
@avg(lock_waits[pid,lock]))
}
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 [...]