1 # futex contention 2 # (c) 2010, Arnaldo Carvalho de Melo <acme (at] redhat.com> 3 # Licensed under the terms of the GNU GPL License version 2 4 # 5 # Translation of: 6 # 7 # http://sourceware.org/systemtap/wiki/WSFutexContention 8 # 9 # to perf python scripting. 10 # 11 # Measures futex contention 12 13 import os, sys 14 sys.path.append(os.environ['PERF_EXEC_PATH'] + '/scripts/python/Perf-Trace-Util/lib/Perf/Trace') 15 from Util import * 16 17 process_names = {} 18 thread_thislock = {} 19 thread_blocktime = {} 20 21 lock_waits = {} # long-lived stats on (tid,lock) blockage elapsed time 22 waker_wakee = {} # maps the futex waker to wakee 23 max_waits = {} # Details about a maximum contention like owner, owner chain 24 process_names = {} # long-lived pid-to-execname mapping 25 26 def android_lock(callchain): 27 for c in callchain: 28 if 'sym' in c and 'name' in c['sym']: 29 name = c['sym']['name'] 30 else: 31 continue 32 33 if 'art::Monitor::Lock' in name: 34 return True 35 return False 36 37 def print_callchain(callchain): 38 for c in callchain: 39 if 'sym' in c and 'name' in c['sym']: 40 name = c['sym']['name'] 41 else: 42 continue 43 44 print(" %s" % (name)) 45 46 def sched__sched_waking(event_name, context, common_cpu, 47 common_secs, common_nsecs, common_pid, common_comm, 48 common_callchain, comm, pid, prio, success, 49 target_cpu): 50 waker_wakee[pid] = [common_pid, common_callchain] 51 52 def syscalls__sys_enter_futex(event, ctxt, cpu, s, ns, tid, comm, callchain, 53 nr, uaddr, op, val, utime, uaddr2, val3): 54 55 cmd = op & FUTEX_CMD_MASK 56 if cmd != FUTEX_WAIT or android_lock(callchain) == False: 57 return # we don't care about originators of WAKE events 58 # or futex uses that aren't android locks. 59 60 process_names[tid] = comm 61 thread_thislock[tid] = uaddr 62 thread_blocktime[tid] = nsecs(s, ns) 63 64 def syscalls__sys_exit_futex(event, ctxt, cpu, s, ns, tid, comm, callchain, 65 nr, ret): 66 67 waker_pid = -1 68 waker_chain = "[no call chain]" 69 70 if thread_blocktime.has_key(tid): 71 # Gather stats about the contention (sum, min, max) 72 elapsed = nsecs(s, ns) - thread_blocktime[tid] 73 add_stats(lock_waits, (tid, thread_thislock[tid]), elapsed) 74 75 # Track details about the maximum contention seen 76 # including owner and its callchain 77 if (tid, thread_thislock[tid]) in max_waits: 78 prev_wait = max_waits[(tid, thread_thislock[tid])][0] 79 else: 80 prev_wait = 0 81 82 if elapsed > prev_wait: 83 if tid in waker_wakee: 84 waker_pid = waker_wakee[tid][0] 85 waker_chain = waker_wakee[tid][1] 86 87 max_waits[(tid, thread_thislock[tid])] = [elapsed, waker_pid, waker_chain, callchain] 88 89 del thread_blocktime[tid] 90 del thread_thislock[tid] 91 92 def trace_begin(): 93 print "Press control+C to stop and show the summary" 94 95 def trace_end(): 96 for (tid, lock) in lock_waits: 97 print("\n==============================================================\n") 98 min, max, avg, count = lock_waits[tid, lock] 99 print "%s[%d] lock %x contended %d times, %d avg ns, %d max ns" % \ 100 (process_names[tid], tid, lock, count, avg, max) 101 print "" 102 103 if not (tid, lock) in max_waits: 104 print"Max contention info not available" 105 continue 106 107 print "Callstack of suffering task:" 108 print_callchain(max_waits[tid, lock][3]) 109 print "" 110 111 waker_pid = max_waits[tid, lock][1] 112 waker_name = process_names[waker_pid] if waker_pid in process_names else "nameless-owner" 113 print "Owner %s caused this contention of %d ns. Owner's Call stack below:" % (waker_name, max_waits[tid, lock][0]) 114 print_callchain(max_waits[tid, lock][2]) 115 116
