gvl-tracing.rb

源码：github.com/ivoanjo/gvl-tracing: Get a timeline view of Global VM Lock usage in your Ruby app

TL;DR

• 使用ruby3.2新增的rb_internal_thread_add_event_hook订阅同是3.2新增的RUBY_INTERNAL_THREAD_EVENT_XXX事件；每当线程状态改变，将当前时间记为该线程原状态的结束时间，以及该线程新状态的开始时间
• 使用rb_tracepoint_new监控ruby3.2新增的RUBY_INTERNAL_EVENT_GC_ENTER和RUBY_INTERNAL_EVENT_GC_EXIT事件；每当回调时，将当前时间记为当前线程原状态的结束时间，以及线程新状态（gc、running）的开始时间

示例

require "gvl-tracing"

def fib(n)
  Object.new
  return n if n <= 1
  fib(n - 1) + fib(n - 2)
end

GvlTracing.start("example1.json", os_threads_view_enabled: false) do
  Thread.new { sleep(0.05) while true }
  sleep(0.05)
  3.times.map { Thread.new { fib(37) } }.map(&:join)
  sleep(0.05)
end

得

[
  {"ph": "M", "pid": 8191, "name": "process_name", "args": {"name": "Ruby threads view (3.3.6)"}},
  {"ph": "E", "pid": 8191, "tid": 0, "ts": 62.000000},
  {"ph": "B", "pid": 8191, "tid": 0, "ts": 62.000000, "name": "started_tracing"},
  {"ph": "E", "pid": 8191, "tid": 1, "ts": 178.000000},
  {"ph": "B", "pid": 8191, "tid": 1, "ts": 178.000000, "name": "started"},
  {"ph": "E", "pid": 8191, "tid": 1, "ts": 207.000000},
  {"ph": "B", "pid": 8191, "tid": 1, "ts": 207.000000, "name": "wants_gvl"},
  {"ph": "E", "pid": 8191, "tid": 0, "ts": 268.000000},
  {"ph": "B", "pid": 8191, "tid": 0, "ts": 268.000000, "name": "waiting"},
  {"ph": "E", "pid": 8191, "tid": 1, "ts": 283.000000},
  {"ph": "B", "pid": 8191, "tid": 1, "ts": 283.000000, "name": "running"},
  {"ph": "E", "pid": 8191, "tid": 1, "ts": 304.000000},
  {"ph": "B", "pid": 8191, "tid": 1, "ts": 304.000000, "name": "waiting"},
  {"ph": "E", "pid": 8191, "tid": 1, "ts": 50774.000000},
  {"ph": "B", "pid": 8191, "tid": 1, "ts": 50774.000000, "name": "wants_gvl"},
  {"ph": "E", "pid": 8191, "tid": 1, "ts": 50782.000000},
  {"ph": "B", "pid": 8191, "tid": 1, "ts": 50782.000000, "name": "running"},
  {"ph": "E", "pid": 8191, "tid": 1, "ts": 50792.000000},
  {"ph": "B", "pid": 8191, "tid": 1, "ts": 50792.000000, "name": "waiting"},
  {"ph": "E", "pid": 8191, "tid": 0, "ts": 55286.000000},
  {"ph": "B", "pid": 8191, "tid": 0, "ts": 55286.000000, "name": "wants_gvl"},
  {"ph": "E", "pid": 8191, "tid": 0, "ts": 55289.000000},
  {"ph": "B", "pid": 8191, "tid": 0, "ts": 55289.000000, "name": "running"},
  {"ph": "E", "pid": 8191, "tid": 2, "ts": 55418.000000},
  {"ph": "B", "pid": 8191, "tid": 2, "ts": 55418.000000, "name": "started"},
  {"ph": "E", "pid": 8191, "tid": 2, "ts": 55465.000000},
  {"ph": "B", "pid": 8191, "tid": 2, "ts": 55465.000000, "name": "wants_gvl"},
  {"ph": "E", "pid": 8191, "tid": 3, "ts": 55513.000000},
  {"ph": "B", "pid": 8191, "tid": 3, "ts": 55513.000000, "name": "started"},
  {"ph": "E", "pid": 8191, "tid": 3, "ts": 55520.000000},
  {"ph": "B", "pid": 8191, "tid": 3, "ts": 55520.000000, "name": "wants_gvl"},
  {"ph": "E", "pid": 8191, "tid": 4, "ts": 55544.000000},
  {"ph": "B", "pid": 8191, "tid": 4, "ts": 55544.000000, "name": "started"},
  {"ph": "E", "pid": 8191, "tid": 4, "ts": 55551.000000},
  {"ph": "B", "pid": 8191, "tid": 4, "ts": 55551.000000, "name": "wants_gvl"},
  {"ph": "E", "pid": 8191, "tid": 0, "ts": 55595.000000},
  {"ph": "B", "pid": 8191, "tid": 0, "ts": 55595.000000, "name": "waiting"},
  {"ph": "E", "pid": 8191, "tid": 2, "ts": 55607.000000},
  {"ph": "B", "pid": 8191, "tid": 2, "ts": 55607.000000, "name": "running"},
  {"ph": "E", "pid": 8191, "tid": 2, "ts": 56135.000000},
  {"ph": "B", "pid": 8191, "tid": 2, "ts": 56135.000000, "name": "gc"},
  {"ph": "E", "pid": 8191, "tid": 2, "ts": 56221.000000},
  {"ph": "B", "pid": 8191, "tid": 2, "ts": 56221.000000, "name": "running"},
  // ...
]

可视化