Mutex sleep is taking a lot of CPU

Question

I profiled my event-machine based application with ruby-prof and found the following interesting:

                  5.28    0.00    5.28    0.00          4/4     Mutex#synchronize
90.72%   0.00%    5.28    0.00    5.28    0.00            4     Mutex#sleep

I think ruby-prof counts only CPU ticks, and hence I'm unable to figure out why mutex sleep might take CPU time. I'd assume it sleeps on the kernel level not counting towards the fiber time. Any ideas? Even better, I'd want the Mutex#sleep to release control to the event machine, so it can do other stuff.

Answer 1

If ruby-prof --mode=cpu is really only accounting CPU time, then Mutex#sleep is a spinlock:

http://en.wikipedia.org/wiki/Spinlock

That would make sense, because you're only supposed to wrap very short assignments in mutex locks. Setting up a signal alarm would be insane overhead.

So the challenge you face is to determine the mutexes you're sleeping on, and what they wrap. Then, you'll either discover avoidable mutex abuse, or unavoidable wait times.