上的输出: Rehearsal -----------------------------------------------------Direct method call 0.350000 0.000000 0.350000 ( 0.352929) method_missing 0.480000 0.000000 0.480000 ( 0.476009) --------------------------------------------- total: 0.830000sec user system total real Direct method call 0.320000 0.000000 0.320000 ( 0.324030) method_missing 0.480000 0.000000 0.480000 ( 0.477420) 第 一组是预演结果,紧接着的是实际度量结果。可以看到,在当前环境下,普通方法调用平均用时 320 纳秒(每百 万次调用用时 0.32 秒),而 method_missing 调用和 case 语句用时 480 纳秒。精确比较两个结果可以发现
使用 method_missing 有 50%的性能损失。与 method_missing 提供的强大功能相比,这点损失还是值得的。 Benchmark 是个强大的工具,但很容易过度使用。除非它是性能瓶颈,否则不需要对方法分派进行优化。不要盲目 地寻找代码进行基准测试。当你想知道哪些地方需要优化时,分析器是更强大的工具。我们将在之后讨论它。 6.1.3 Rails Analyzer Tools Rails Analyzer Tools(rails-analyzer.rubyforge.org/)是一组帮助你分析 Rails 应用
程序的工具。 Benchmark 对 Ruby 特别有效,httperf 用于度量 web 网站,而 Rails Analyzer Tools 是针对 Rails 写的。 6.1.3.1 Production log analyzer 第 一个工具,production 日志分析器,通过扫描生产环境下的日志文件来找出部署好的应用中最慢的 action。它 对解决问题非常有用,但有很强的局限性。它要求通过 SyslogLogger(由 Rails Analyzer Tools 提供)来记录日 志,你必须预先设置好它。它还需要一个支持按程序名过滤的 syslogd,这通常意味着运行 BSD
系统或者安装 syslogng。基于以上原因,在此我们不深入讨论它。完整的安装介绍可见 railsanalyzer.rubyforge.org/pl_analyze/。 6.1.3.2 Action Profiler 一 旦确定了哪些 action 影响了性能,你需要一种方法来找出更深层的原因。Action Profiler 是一个库(也有一个 对应的可执行程序,action_profiler),将 Rails 与分析器连接起来。它通过整个 Rails 栈和应用 程序代码来分析单个
Rails action,这样可以检查出在 action 执行过程中时间都花在哪些地方。 Action Profiler 可被多个分析引擎使用,如 ZenProfiler,ruby-prof 以及 Ruby 内建的 Profiler 类。如果没用在命 令行中通过- P 选项指定使用哪个引擎,将按上述顺序尝试找出一个可用的。以下是一个运行 Ruby Profile 的示例,包 括扁平调用结果分析: $ action_profiler -P Profiler ListingController#map Warmup... Profiling... % cumulative self self total time seconds seconds calls ms/call ms/call name 13.73 0.07 0.07 204 0.34 0.34 ERB::Util.html_escape 11.76 0.13 0.06 1462 0.04 0.08 String#gsub 11.76 0.19 0.06 6 10.00 10.00 AssetTagHelper. compute_public_path 9.80 0.24 0.05 89 0.56 0.67 FormOptionsHelper. option_value_selected? 9.80 0.29 0.05 178 0.28 0.28 Array#<< 3.92 0.31 0.02 44 0.45 6.36 Array#each 3.92 0.33 0.02 287 0.07 0.07 Kernel.respond_to? 3.92 0.35 0.02 89 0.22 0.45 Array#each_index 3.92 0.37 0.02 89 0.22 0.34 Inflector.humanize 1.96 0.38 0.01 179 0.06 0.06 Kernel.=== 1.96 0.39 0.01 67 0.15 0.15 String#concat 1.96 0.40 0.01 16 0.63 0.63 ActionView::Base# template_exists? 1.96 0.41 0.01 613 0.02 0.02 String#to_s 1.96 0.42 0.01 7 1.43 1.43 MonitorMixin.synchronize (以及更多行...) 结果包含以下列。 列名 描述 % Time 只花在这个函数上的时间所占百分比 Cumulative Seconds 花在这个函数上的总秒
数,包括在这个函数里调用其他函数所花的时间 Self Seconds 只花在这个函数上的总秒数,不包含在这个函数里调用其他函数所花