Attachment 901514 Details for Bug 1011221 – aconway's stap script

aconway's stap script

mutexes.stp (text/plain), 3.10 KB, created by mick on 2014-06-02 17:56:18 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: mick

Created: 2014-06-02 17:56:18 UTC

Size: 3.10 KB

patch

obsolete

>//!/usr/bin/stap
>//
>// This script identifies contended mutex locks by a stack trace.
>// Run with -x and -d for a particular process, e.g. for qpidd:
>//
>//     sudo stap ~/stap/mutexes.stp -x $(pgrep qpidd) -d $(which qpidd) --ldd -v
>//
>// While the script is running, it prints the address of each contended mutex
>// on the first contended lock to show progress.
>//
>// When the script is killed (Ctrl-C or kill -int) it prints statistics for
>// contended lock wait times and a stack trace to one of the contended lock locations
>// for the most contended locks.
>//
>// Filter the output with c++filt to get readable C++ function names.
>//
>// TODO:
>// 
>// The trace gives an address, function and library. Would be nice to
>// convert the address into a file:line to precisely identify the
>// lock statement. addr2line should be able to do this but haven't figured it
>// out yet.
>//
>// Might also be interesting to do statistics by contended lock
>// location rather than by mutex.
>//
>
>global thread_contended		  // time of latest contended lock call on thread.
>global mutex_waits                // stats on contended wait times by mutex.
>global mutex_locks		  // number of threads currently attempting to lock mutex.
>global mutex_stacks		  // stack traces per mutex
>
>
>probe process("/lib64/libpthread.so.0").function("pthread_mutex_lock") {
>  if (target() == pid()) {
>    if (++mutex_locks[$mutex] > 1) // Contended
>	thread_contended[tid()] = gettimeofday_us();
>  }
>}
>
>probe process("/lib64/libpthread.so.0").function("pthread_mutex_lock").return {
>  // Note: this is lock.return so at this point the current thread is holding
>  // the lock. No other thread can modify mutex_waits[$mutex] till this thread
>  // calls unlock.
>  if (target() == pid()) {
>    contended = thread_contended[tid()];
>    if (contended) {
>      delete thread_contended[tid()]
>      mutex_waits[$mutex] <<< (gettimeofday_us() - contended);
>      if (@count(mutex_waits[$mutex]) == 1) {   // First contention of this mutex
>	printf ("mutex %p contended\n", $mutex)
>	// We need to print the stack trace here, not in end() to get a useful trace.
>	mutex_stacks[$mutex] = sprint_ubacktrace()
>      }
>    }
>  }
>}
>
>probe process("/lib64/libpthread.so.0").function("pthread_mutex_unlock") {
>  if (target() == pid()) {
>    // TODO: by inspection there is a race here, unless stap is doing some magic:
>    // - this thread does --mutex_locks[$mutex] and sees 0
>    // - another thread hits the lock probe and does ++mutex_locks[$mutex]
>    // - this thread does delete mutex_locks[$mutex] and nukes a non-0 value
>    // Consequence: we could miss contentions. However we can't drop
>    // the delete or we overrun the mutex_locks array.
>    if (--mutex_locks[$mutex] <= 0)
>      delete mutex_locks[$mutex];
>  }
>}
>
>probe end {
>  printf("\n\nContended mutexes, most frequent first\n\n")
>  foreach ([m] in mutex_waits- limit 100) {
>    printf ("==== mutex %p contended %d times, %dus total, %dus avg\n",
>	    m,
>	    @count(mutex_waits[m]),
>	    @sum(mutex_waits[m]),
>	    @avg(mutex_waits[m]))
>    printf("%s\n\n", mutex_stacks[m])
>  }
>}

Actions: View

Attachments on bug 1011221: 899962 | 901470 | 901514 | 905459 | 907702 | 912758 | 919951 | 920122 | 929675