Windows上でスレッドトレースする

nmosh teslawire

(おおきいの - http://storage.osdev.info/pub/idmjt/diaryimage/1405/neta140509l1.png )
ETW(Event Tracing for Windows)を使用するとDTraceやftraceのようなスケジューリングトレースを(比較的低いオーバヘッドで)取得することができる。ETWのログビューアとしてはWPA(Windows Performance Analyzer)が提供されているので、直ぐに内容を検証することができる。
↑では、BoehmGCのparallel markを有効にしたnmoshでR6RS test suiteを実行し、GCが動作したところをズームしている。ポインタが指している部分がメインスレッド(TIDが一番若い)で、残りがBoehmGCが起動したGCスレッドとなる。実際には、メインスレッドもGC動作を行うため、全スレッドが稼動しているように見える。(incremental collectionを有効にしていないので、GC中はインタプリタは停止状態となる。)
ETWを有効にするコマンドラインツールとしてxperfが提供されている。手元のWindows SDKでは、C:\Program Files (x86)\Windows Kits\8.1\Windows Performance Toolkitに一式が配置されていた。xperfは管理者権限で実行する必要がある。

  • キャプチャの開始
xperf -on proc_thread+cswitch+syscall -stackwalk cswitch -filemode circular -maxfile 1024 -buffersize 4096 -maxbuffers 4096
  • キャプチャの停止
xperf -d out.etl

タイムラインにある2つのグラフのうち、上部がnmoshプロセス中のスレッドのスケジューリング状態を可視化したもので、下部がハードウェアスレッド毎(このPCはHyperThreadingを有効にしているため、実際の物理CPUは4つ)でスケジュールされているスレッドを可視化したものとなる。下部のグラフでは、ピンク色がnmoshのスレッドであり、他のプロセスは別の色で表わされる。
グラフから、GCの終盤ではComputation(画面左のグラフ)が低下しており、GCの並列度が低下していることが観察できる。また、下部のグラフでCPU4に他のプロセスの割り込みが観察される。この割り込んでいるプロセスはrtp-midiで、このプロセスは高優先度スレッドを1ms周期で動作させている。
Windowsにはスレッドに名前を付ける直接的な仕組みが存在しないため、WPAも良いアノテーションを提供できない。また、WPAはフレーム分割などのゲームアプリケーションに必要な機能を提供していない。この目的のためにはGPUView( http://msdn.microsoft.com/en-us/library/windows/desktop/jj585574%28v=vs.85%29.aspx )が有り、これもETWを基盤として使用している。