无意间发现ruby中一个非常实用的gem包----Profile
英语比较烂,不知道什么意思,百度一下:1. 侧面(像),侧影,2. 轮廓,外形;外观;形象,3. 纵断面(图),剖面(图)
还不如不查,晕菜了。。
来看个实例:
首先下载profile的gem包
?
?
gem install profile
安装成功后运行如下代码:
?
?
require "profile" class Peter def initialize(amt) @value = amt end def rob(amt) @value -= amt amt end end class Paul def initialize @value = 0 end def pay(amt) @value += amt amt end end
start_time = Time.now peter = Peter.new(1000) paul = Paul.new 1000.times do paul.pay(peter.rob(10)) end end_time = Time.now puts end_time - start_time
?运行结果让人有点吃惊:
?
0.15625 % cumulative self self total time seconds seconds calls ms/call ms/call name 30.13 0.05 0.05 1 47.00 156.00 Integer#times 30.13 0.09 0.05 1000 0.05 0.06 Paul#pay 19.87 0.13 0.03 1000 0.03 0.05 Peter#rob 10.26 0.14 0.02 1000 0.02 0.02 Fixnum#+ 9.62 0.16 0.01 1000 0.01 0.01 Fixnum#- 0.00 0.16 0.00 2 0.00 0.00 IO#write 0.00 0.16 0.00 1 0.00 0.00 Kernel.puts 0.00 0.16 0.00 1 0.00 0.00 Peter#initialize 0.00 0.16 0.00 2 0.00 0.00 Class#inherited 0.00 0.16 0.00 1 0.00 0.00 Time#- 0.00 0.16 0.00 2 0.00 0.00 Time#now 0.00 0.16 0.00 1 0.00 0.00 Float#to_s 0.00 0.16 0.00 2 0.00 0.00 Class#new 0.00 0.16 0.00 1 0.00 0.00 Paul#initialize 0.00 0.16 0.00 2 0.00 0.00 Time#initialize 0.00 0.16 0.00 4 0.00 0.00 Module#method_added 0.00 0.16 0.00 1 0.00 156.00 #toplevel
?这一看,大概知道这个gem是干什么的了,是用来分析函数的执行时间的
?time(%): 该函数执行时间占用总时间的百分比,当然比例越高说明这句可能需要优化
?calls:被调用的次数
?name:对应的函数
?ms//call : 函数执行共用时间
?可以看出,times执行了一次,但是执行时间为156ms, 几乎等于整个程序的执行时间0.15625s,执行了1000次的4个
?函数的用时也很明显,可以用来分析程序的执行效率,是个很不错的东西,而且源代码只有20几kb
?
另外一种运行方式:ruby -rprofile my_program
可以不需要require profile达到同样的目的
?
参考资料:
http://www.caliban.org/ruby/rubyguide.shtml
http://rubydoc.info/gems/profile/0.3.3/frames
?
?