Class: ZenProfiler

Inherits:
EventHook
  • Object
show all
Defined in:
lib/zenprofiler.rb

Overview

ZenProfiler provides a faster version of the standard library ruby profiler. It is otherwise pretty much the same as before.

Invoke it via:

% zenprofile misc/factorial.rb

or:

% ruby -rzenprofile misc/factorial.rb

Constant Summary collapse

VERSION =
'1.3.2'
@@start =
nil
@@stack =
[[0, 0, [nil, :toplevel]], [0, 0, [nil, :dummy]]]
@@map =
Hash.new { |h,k| h[k] = [0, 0.0, 0.0, k] }
@@percent_time_threshold =
0.5

Class Method Summary collapse

Class Method Details

.percent_time_thresholdObject



41
42
43
# File 'lib/zenprofiler.rb', line 41

def self.percent_time_threshold
  @@percent_time_threshold
end

.percent_time_threshold=(percent_time_threshold) ⇒ Object



45
46
47
# File 'lib/zenprofiler.rb', line 45

def self.percent_time_threshold=(percent_time_threshold)
  @@percent_time_threshold = percent_time_threshold
end


49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
# File 'lib/zenprofiler.rb', line 49

def self.print_profile(f, opts = {})
  stop_hook

  @@total = Time.now.to_f - @@start
  @@total = 0.01 if @@total == 0
  @@total2 = Process.times[0] - @@start2
  @@map["#toplevel"][1] = @@total
  data = @@map.values.sort_by { |vals| -vals[2] }
  sum = 0

  f.puts "Total time = %f" % @@total
  f.puts "Total time = %f" % @@total2
  f.puts
  f.puts "          total     self              self    total"
  f.puts "% time  seconds  seconds    calls  ms/call  ms/call  name"

  @@total = data.inject(0) { |acc, (_, _, self_ms, _)| acc + self_ms }

  data.each do |calls, total_ms, self_ms, name|
    percent_time = self_ms / @@total * 100.0

    next if percent_time < @@percent_time_threshold

    sum += self_ms
    klass = name.first
    meth  = name.last.to_s

    signature =
      if klass.nil?
        meth
      elsif klass.kind_of?(Module)
        klassname = klass.name rescue klass.to_s.sub(/#<\S+:(\S+)>/, '\\1')
        "#{klassname}##{meth}"
      else
        "#{klass}##{meth}"
      end

    f.printf "%6.2f ",  percent_time
    f.printf "%8.2f ", sum
    f.printf "%8.2f ",  self_ms
    f.printf "%8d ",    calls
    f.printf "%8.2f ",  (self_ms * 1000.0 / calls)
    f.printf "%8.2f ",  (total_ms * 1000.0 / calls)
    f.printf "%s",      signature
    f.puts
  end
end

.process(event, obj, method, klass) ⇒ Object



98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
# File 'lib/zenprofiler.rb', line 98

def self.process event, obj, method, klass
  case event
  when CALL, CCALL
    now = Process.times[0]
    @@stack.push [now, 0.0]
  when RETURN, CRETURN
    klass = klass.name rescue return
    key = [klass, method]
    if tick = @@stack.pop
      now = Process.times[0]
      data = @@map[key]
      data[0] += 1
      cost = now - tick[0]
      data[1] += cost
      data[2] += cost - tick[1]
      @@stack[-1][1] += cost if @@stack[-1]
    end
  end
end

.run(fp = $stdout, opts = {}) ⇒ Object



28
29
30
31
32
33
# File 'lib/zenprofiler.rb', line 28

def self.run(fp = $stdout, opts = {})
  at_exit {
    ZenProfiler::print_profile fp, opts
  }
  ZenProfiler::start_hook
end

.start_hookObject



35
36
37
38
39
# File 'lib/zenprofiler.rb', line 35

def self.start_hook
  @@start  ||= Time.now.to_f
  @@start2 ||= Process.times[0]
  super
end