Rubyでmutexの競合を測定するにはどうすればよいですか？

Question

私は最近、特定のRubyプログラムがなぜ遅いのかを診断しようとしていました。結局のところ、スケーリングの問題が原因で特定のミューテックスに多数の競合が発生していました。

私は、この問題を診断しやすくするために使用していた可能性のあるツールがあるかどうか疑問に思っていましたか？私は、このプログラムの100以上のスレッドが時間を費やしていることの詳細な出力を得るためにRuby-Profを使用することができたことを知っていますが、Rubyでのmutex競合の測定に特に重点を置いているツールがあるかどうか不思議です。

Answer 1

だから、もしDTraceでこれを行う方法が分かったら。

このようなRubyプログラムを考える：私たちはRubyのプログラムに対してこのスクリプトを実行すると、私たちは、このような情報を取得

/* mutex.d */ 
ruby$target:::cmethod-entry 
/copyinstr(arg0) == "Mutex" && copyinstr(arg1) == "synchronize"/ 
{ 
    self->file = copyinstr(arg2); 
    self->line = arg3; 
} 

pid$target:ruby:rb_mutex_lock:entry 
/self->file != NULL && self->line != NULL/ 
{ 
    self->mutex_wait_start = timestamp; 
} 

pid$target:ruby:rb_mutex_lock:return 
/self->file != NULL && self->line != NULL/ 
{ 
    mutex_wait_ms = (timestamp - self->mutex_wait_start)/1000; 
    printf("Thread %d acquires mutex %d after %d ms - %s:%d\n", tid, arg1, mutex_wait_ms, self->file, self->line); 
    self->file = NULL; 
    self->line = NULL; 
} 

：我々はこのようなDTraceスクリプトを使用することができます

# mutex.rb 
mutex = Mutex.new 
threads = [] 

threads << Thread.new do 
    loop do 
    mutex.synchronize do 
     sleep 2 
    end 
    end 
end 

threads << Thread.new do 
    loop do 
    mutex.synchronize do 
     sleep 4 
    end 
    end 
end 

threads.each(&:join) 

を：

$ sudo dtrace -q -s mutex.d -c 'ruby mutex.rb' 

Thread 286592 acquires mutex 4313316240 after 2 ms - mutex.rb:14 
Thread 286591 acquires mutex 4313316240 after 4004183 ms - mutex.rb:6 
Thread 286592 acquires mutex 4313316240 after 2004170 ms - mutex.rb:14 
Thread 286592 acquires mutex 4313316240 after 6 ms - mutex.rb:14 
Thread 286592 acquires mutex 4313316240 after 4 ms - mutex.rb:14 
Thread 286592 acquires mutex 4313316240 after 4 ms - mutex.rb:14 
Thread 286591 acquires mutex 4313316240 after 16012158 ms - mutex.rb:6 
Thread 286592 acquires mutex 4313316240 after 2002593 ms - mutex.rb:14 
Thread 286591 acquires mutex 4313316240 after 4001983 ms - mutex.rb:6 
Thread 286592 acquires mutex 4313316240 after 2004418 ms - mutex.rb:14 
Thread 286591 acquires mutex 4313316240 after 4000407 ms - mutex.rb:6 
Thread 286592 acquires mutex 4313316240 after 2004163 ms - mutex.rb:14 
Thread 286591 acquires mutex 4313316240 after 4003191 ms - mutex.rb:6 
Thread 286591 acquires mutex 4313316240 after 2 ms - mutex.rb:6 
Thread 286592 acquires mutex 4313316240 after 4005587 ms - mutex.rb:14 
... 

この出力を収集し、それを使用してどのミュートxesが最大の競合を引き起こしています。