How to debug a futex contention shown in strace?

Question

I'm debugging an issue in a multi-threaded linux process, where a certain thread appears to not execute for few seconds. Looking at strace output revealed it waits for futex e.g.
1673109 14:36:28.600329 futex(0x44b8d20, FUTEX_WAIT_PRIVATE,
1673109 14:36:33.221850 <... futex resumed> ) = 0 <4.621514>

How can I find out out what this futex(0x44b8d20) refers to in user space, i.e. how to map this to a locking construct which is using futex internally.

Answer 1

I would use a simple systemtap script so that would help you to quickly find out addresses of contended futex locks. When I say address, I am referring to the first argument of futex() syscall.

1. You can download the simple system tap script that finds the contended user space locks here:
   https://sourceware.org/systemtap/examples/process/futexes.stp

   If you have systemtap installed on your system,
   just start this system tap script: stap futexes.stp

2. Capture the strace output as you did before.

3. If you end the system tap script execution by simply doing Ctrl-C,
   you will get the output of contended futexes.

4. Finally in your strace output,
   search for futex calls in which the second argument (operation type) is FUTEX_WAIT.
   For example : futex(0x7f58a31999d0, FUTEX_WAIT, 4508, NULL) = 0

5. Then you can search for the first argument in system tap script output.
   Something like : ome[4489] lock 0x7f58a31999d0 contended 1 times, 7807 avg us

If you look at this system tap script,
it nicely prints the process name and process/thread id for you.
This makes it easy to find what you are looking for.

However one note is that executing the systemtap script will actually hook a syscall system wide.