Ruby GC timing discrepancy
#!/usr/bin/env ruby | |
puts "Run this in another terminal:" | |
puts "" | |
puts " sudo ./trace-gc-standalone.sh #{$$}" | |
puts "" | |
puts "... wait for the 'Ready!' message, switch back here and press enter to start." | |
GC::Profiler.enable | |
$stdin.gets | |
GC::Profiler.clear | |
time_before = GC::Profiler.total_time | |
# Generate some GC stress... | |
300.times do | |
symbols = (1..1000).to_a.map { |i| "s#{i}".to_sym }.shuffle | |
10.times { symbols.sort } | |
end | |
time_after = GC::Profiler.total_time | |
records = GC::Profiler.raw_data | |
total_gc_time = time_after - time_before | |
mark_times = records.map { |r| r[:GC_MARK_TIME] }.compact | |
sweep_times = records.map { |r| r[:GC_SWEEP_TIME] }.compact | |
total_mark_time = mark_times.inject(:+) | |
total_sweep_time = sweep_times.inject(:+) | |
puts "Total mark time: %.1f ms" % [total_mark_time * 1000] | |
puts "Total sweep time: %.1f ms" % [total_sweep_time * 1000] | |
puts "Total GC time: %.1f ms" % [total_gc_time * 1000] |
#!/bin/bash | |
PID=$1 | |
cat > /tmp/dtracetmp.$$ <<EOF | |
#!/usr/sbin/dtrace -s | |
#pragma D option bufsize=16m | |
#pragma D option dynvarsize=16m | |
#pragma D option cleanrate=50Hz | |
BEGIN { | |
printf("Ready! (Go press enter on the original script.)\n"); | |
} | |
ruby${PID}:::gc-mark-begin { | |
self->mark_begin = timestamp; | |
} | |
ruby${PID}:::gc-mark-end /self->mark_begin/ { | |
elapsed = timestamp - self->mark_begin; | |
@mark_total = sum(elapsed); | |
@total = sum(elapsed); | |
self->mark_begin = 0; | |
} | |
ruby${PID}:::gc-sweep-begin { | |
self->sweep_begin = timestamp; | |
} | |
ruby${PID}:::gc-sweep-end /self->sweep_begin/ { | |
elapsed = timestamp - self->sweep_begin; | |
@sweep_total = sum(elapsed); | |
@total = sum(elapsed); | |
self->sweep_begin = 0; | |
} | |
END { | |
normalize(@mark_total, 1000000); | |
normalize(@sweep_total, 1000000); | |
normalize(@total, 1000000); | |
printa("Mark total: %@d ms\n", @mark_total); | |
printa("Sweep total: %@d ms\n", @sweep_total); | |
printa("Mark + sweep total: %@d ms\n", @total) | |
} | |
EOF | |
dtrace -q -s /tmp/dtracetmp.$$ -p $PID |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment