benweint / standalone.rb

Created March 13, 2014


    
    View standalone.rb 
  
  
      standalone.rb
    
    
        Raw
      
    
    File suppressed. Click to show.
  
  
            1
            2
            3
            4
            5
            6
            7
            8
            9
            10
            11
            12
            13
            14
            15
            16
            17
            18
            19
            20
            21
            22
            23
            24
            25
            26
            27
            28
            29
            30
            31
            32
            33
          
          
            #!/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]

          
    View standalone.rb 
  
  
      trace-gc-standalone.sh
    
    
        Raw
      
    
    File suppressed. Click to show.
  
  
            1
            2
            3
            4
            5
            6
            7
            8
            9
            10
            11
            12
            13
            14
            15
            16
            17
            18
            19
            20
            21
            22
            23
            24
            25
            26
            27
            28
            29
            30
            31
            32
            33
            34
            35
            36
            37
            38
            39
            40
            41
            42
            43
            44
            45
            46
            47
            48
            49
          
          
            #!/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