DIY Ruby CPU 分析 Part II

【编者按】做者 Emil Soman，Rubyist，除此以外居然同时也是艺术家，吉他手，Garden City RubyConf 组织者。本文是 DIY Ruby CPU Profiling 的第二部分。本文系 OneAPM 工程师编译整理。

原文连接：http://crypt.codemancers.com/posts/2015-03-06-diy-ruby-cpu-profiling-part-i/

在第一部分中咱们学习了 CPU 分析的含义和进行 CPU 分析的两种方法，点此处回顾第一篇精彩内容。在这一部分咱们将研究 CPU time 和 Wall time，这些部分总被用来测量执行开销。咱们也会写一些实现这些测量方法的代码做为创建 CPU 分析的第一步。

Part II. CPU time 和 Wall time

Wall time

Wall time 是在一个方法被调用和返回之间的真实时间。所以，若是你想要测量一个方法执行的 「Wall clock time」，理论上能够用秒表来测量。只要在方法开始执行时打开秒表，在方法返回时按下中止。这个时间一般也被称为真实时间。

关于 Wall time 很重要的一点是，能够预见，每次试图测量同一段代码可能获得不一样的结果。这是由于一系列后台进程会影响 Wall time. 当 CPU 同时运行多个进程的时候，操做系统给同时运行的进程排期而且试图为它们公平的分配 CPU 空间。这意味着 CPU 花费的总时间被分红多个片而咱们的方法只占用其中的一些时间片。所以，当 Wall clock 开始计时，咱们的进程可能会闲置而且为并行运行的其余进程让路。这意味着花费在其余进程的时间将增长咱们的 Wall time!

CPU time

CPU time 是指 CPU 执行方法的时间。CPU time 的度量单位是用于执行方法的 CPU 时钟周期。若是咱们了解 CPU 频率，它的单位是周期每秒，也能够称做赫兹，那么咱们能够将其转换为时间。若是 CPU 执行某一方法花了 x 个时钟周期，这个 CPU 频率是 y 赫兹，那么 CPU 执行方法的时间为 x/y 秒。有时操做系统会为咱们自动进行转换从而使咱们免于进行这种计算。

CPU 时间不等同于 Wall time，其中的差异在于方法的指令类型。咱们能够宽泛的将指令分为两种类型：CPU 密集型 和 I/O 密集型. 在执行 I/O 指令时，CPU 空闲下来能够转去执行其余 CPU 密集型指令。所以，若是咱们的方法在 I/O 指令上花费时间，CPU 能够不把时间投入在该方法上，而是去处理其余事情，直到 I/O 操做完成。 这段时间内 Wall time 在计时而 CPU time 中止计时，落后于 Wall time.

咱们来看看一个须要5分钟来执行的慢方法的状况。若是想知道这个方法花费了多长时间，你的 Wall clock 能够显示「执行该方法须要五分钟」，但 CPU 会显示「执行该方法中用时 3 分钟」。因此应该遵从哪个说法呢？究竟哪一个时间可以更准确的测量执行方法的时间？

答案是：看状况。这取决于你但愿测量的方法的类型。若是该方法的大部分时间用于 I/O 操做，或者该方法没有直接处理 CPU 密集型指令，由 CPU time 描述的时间开销将十分不许确。对于这些类型的方法，经过 Wall time 来测量时间更加合适。而对于其余状况，坚持经过 CPU time 来测量是很可靠的。

测量 CPU time 和 Wall time

鉴于想要写一个 CPU 分析器，咱们须要一种测量 CPU time 和 Wall time 的方法。下面来看一看已经可以测量这两项的 Ruby 的 Benchmark module 中的代码。

def measure(label = "") # :yield:
  t0, r0 = Process.times, Process.clock_gettime(BENCHMARK_CLOCK)
  yield
  t1, r1 = Process.times, Process.clock_gettime(BENCHMARK_CLOCK)
  Benchmark::Tms.new(t1.utime  - t0.utime,
                     t1.stime  - t0.stime,
                     t1.cutime - t0.cutime,
                     t1.cstime - t0.cstime,
                     r1 - r0,
                     label)
end

因而可知，Ruby 经过两种进程类中的方法来测量时间：

1. 经过times测量 CPU time.

2. 经过clock_gettime来测量真实时间，也就是 Wall time.

可是times方法返回的结果为1秒，这表示经过分析器用times只能测量仅须要几秒就能完成的 方法的 CPU time. 然而clock_gettime就有趣多了。

clock_gettime

Process::clock_gettime是早在 Ruby 2.1 版本就已经被添加的方法，它使用 POSIX clock_gettime()功能并回退到 OS 仿真来得到时间以防clock_gettime在 OS 中失效或没法实施。该功能接受clock_id及时间结果做为参数。有不少能够被选为这种计时器的clock_ids，但咱们感兴趣的是：

1. CLOCK_MONOTONIC: 这个计时器测量逃走的 Wall clock time，由于过去的任意时间点不会被系统时钟的变化影响，最适合测量 Wall time.

2. CLOCK_PROCESS_CUPTIME_ID: 这个计时器测量每个进程的 CPU time，意即计算进程中全部线程的时间。咱们能够用它来测量 CPU time.

让咱们利用这个来写一些代码：

module DiyProf
  # These methods make use of `clock_gettime` method introduced in Ruby 2.1
  # to measure CPU time and Wall clock time.

  def self.cpu_time
    Process.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :microsecond)
  end

  def self.wall_time
    Process.clock_gettime(Process::CLOCK_MONOTONIC, :microsecond)
  end
end

能够在 benchmark 代码中使用这些方法：

puts "****CPU Bound****"
c1, w1 = DiyProf::cpu_time, DiyProf::wall_time
10000.times do |i|
  Math.sqrt(i)
end
c2, w2 = DiyProf::cpu_time, DiyProf::wall_time
puts "CPU time\t=\t#{c2-c1}\nWall time\t=\t#{w2-w1}"

puts "\n****IO Bound****"
require 'tempfile'

c1, w1 = DiyProf::cpu_time, DiyProf::wall_time
1000.times do |i|
  Tempfile.create('file') do |f|
    f.puts(i)
  end
end
c2, w2 = DiyProf::cpu_time, DiyProf::wall_time
puts "CPU time\t=\t#{c2-c1}\nWall time\t=\t#{w2-w1}"

运行这些代码会得出相似如下的结果：

****CPU Bound****
CPU time    =    5038
Wall time    =    5142

****IO Bound****
CPU time    =    337898
Wall time    =    475864

这些清楚地展示了单个 CPU 内核的状况，在仅运行 CPU 密集型指令时 CPU time 和 Wall time 几乎相等，而运行 I/O 密集型指令时 CPU time 老是少于 Wall time.

归纳

咱们学习了 CPU time 和 Wall time 的含义与差别，以及何时用哪一种。与此同时，写了一些 Ruby 代码来测量 CPU time 和 Wall time 来为咱们作的 CPU 分析器测量时间。在第三部分咱们将讨论 Ruby TracePoint API 并利用它作一个仪表分析器。

---

OneAPM for Ruby 可以深刻到全部 Ruby 应用内部完成应用性能管理和监控，包括代码级别性能问题的可见性、性能瓶颈的快速识别与追溯、真实用户体验监控、服务器监控和端到端的应用性能管理。 想阅读更多技术文章，请访问 OneAPM 官方博客。