DIY Ruby CPU 分析——Part III

Stella981
• 阅读 622

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

原文链接:http://crypt.codemancers.com/posts/2015-04-15-diy-ruby-cpu-profiling-part-iii/ DIY Ruby CPU 分析——Part III 在第一部分我们了解到仪表分析器如何工作,在第二部分我们学习到如何使用 CPU time 和 Wall time 测量执行时间。建议在继续学习之前先阅读一下那些内容。本章我们将应用学到的目前为止知识做一个很基础的仪表 CPU 分析器。 ###Part III. DIY 仪表 CPU 分析器 #####Ruby 的仪表盘 在第一部分,我们学到了仪表分析工具利用能够被分析工具安装或由语言自身提供的 hooks 来工作。幸运的是,Ruby 早就拥有这些 hooks 并且提供纤巧的TracePoint类来使用这些 hooks。 #####TracePoint API 执行代码时,Ruby VM 发送一系列事件到不同的节点。Ruby 允许利用TracePoint类进行事件回调。TracePoint的 API 文档列出了所有可以监听的事件,但我们只对下面两个感兴趣:

  1. :call,当 Ruby 方法调用时被触发。

  2. :return, 当 Ruby 方法返回时被触发。 我们可以通过TracePoint.new方法创造 tracepoint 对象并传递一个事件类型进行监听,同时传递部分在事件触发时执行的代码。下面是为:call:return事件创造 tracepoint 的代码。

    trace = TracePoint.new(:call, :return) do |trace| puts "Method: #{trace.method_id}, event: #{trace.event}" end

被传到回调代码块的参数trace使你能够访问一系列 tracepoint 的属性,通过它们更加了解被触发的事件。举个例子,我们需要通过method_id属性得到 method name,通过event属性得到被触发的事件名。上文提到的回调代码块中将显示出方法名和被触发的事件类型,每一次都会伴随着 Ruby 方法的调用或返回。 建立 tracepoint 之后,需要将其变成可用状态:

trace.enable

一旦 tracepoint 变成可用状态,我们便可以创建方法对它进行调用,并且看我们出发的回调命令是否被执行。

def hello
end

hello

#=> Method: hello, event: call
#=> Method: hello, event: return

不错,我们的回调命令如预期的一样被执行了两次。 #####diy_prof gem 最后我们将结合之前学过的东西创造一个 RubyGem,并将这个 gem 命名为 diy_prof. 关于此 gem 的资源放在 github 上。 现在我们就用 bundler 来建造这个 gem:

bundle gem diy_prof

这就造出了我们将要做的项目的骨架。接着,我们将建立在 Part II 中介绍过的包含cpu_timewall_time方法的 TimeHelpers模块:

# lib/diy_prof/time_helpers.rb

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

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

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

我们还需要请求 gem 主文件中的这个文件lib/diy_prof.rb

# lib/diy_prof.rb

require 'diy_prof/version'
require 'diy_prof/time_helpers'
# Rest of the original file ..

下一步,当一个:callreturn事件发生时,我们将通过 gem 里的 TracePoint API 来显示时间。

module DiyProf
  class Tracer
    include TimeHelpers

    def initialize(clock_type: :cpu)
      @tracepoint = TracePoint.new(:call, :return) do |trace|
        time = clock_type == :wall ? wall_time : cpu_time
        printf("%-20s:%-20s%-20s\n", time, trace.event, trace.method_id)
      end
    end
    def enable
      @tracepoint.enable
    end

    def disable
      @tracepoint.disable
    end
  end
end

同时,我们需要再一次调用这个 gem 主文件中的文件:

# lib/diy_prof.rb

require 'diy_prof/version'
require 'diy_prof/time_helpers'
require 'diy_prof/tracer'
# Rest of the original file ..

现在,让我们来写一个例子脚本来测试至今为止创造了什么。我们将使用在 Part I 中见过的那个例子:

# examples/demo.rb

$:<< File.join(File.dirname(__FILE__), "../lib")
require 'diy_prof'

### Begin sample program ###
def main
  3.times do
    find_many_square_roots
    find_many_squares
  end
end

def find_many_square_roots
  5000.times{|i| Math.sqrt(i)}
end

def find_many_squares
  5000.times{|i| i**2 }
end
### End sample program ###

tracer = DiyProf::Tracer.new(clock_type: :cpu)
tracer.enable
main
tracer.disable

如果运行了以上 Ruby 程序,我们将得到下列结果: DIY Ruby CPU 分析——Part III 第一列显示的是被触发事件的 CPU time,第二列是被触发的事件名,第三列是被调用或返回的方法名。这个结果与在 Part I 中学习仪表分析器如何工作时看到的结果很相似。可以看到,我们能够轻松地通过这个结果重建调用,因为我们可以知道各个方法间的调用关系。写一个能解析这个结果并按执行时间有序显示方法列的脚本并不是很难。但这太无聊了,我们可以建造更有趣的东西。看着吧,下一部分将学习我们能够利用这些数据来做的其他事情。 #####概括 我们学习了 Ruby 的 TracePoint API 以及如何用它监听方法的调用和返回。同时我们整合写过的代码建立了一个能够显示 Ruby 程序的执行 trace 的 gem。在第四部分我们将学习如何有效利用 gem 收集到的数据并通过它们创造一些很酷的调用图。感谢阅读!如果你想要阅读 DIY CPU 分析系列的其他最新文章,请关注我们的 twitter @codemancershq.

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

点赞
收藏
评论区
推荐文章
blmius blmius
3年前
MySQL:[Err] 1292 - Incorrect datetime value: ‘0000-00-00 00:00:00‘ for column ‘CREATE_TIME‘ at row 1
文章目录问题用navicat导入数据时,报错:原因这是因为当前的MySQL不支持datetime为0的情况。解决修改sql\mode:sql\mode:SQLMode定义了MySQL应支持的SQL语法、数据校验等,这样可以更容易地在不同的环境中使用MySQL。全局s
皕杰报表之UUID
​在我们用皕杰报表工具设计填报报表时,如何在新增行里自动增加id呢?能新增整数排序id吗?目前可以在新增行里自动增加id,但只能用uuid函数增加UUID编码,不能新增整数排序id。uuid函数说明:获取一个UUID,可以在填报表中用来创建数据ID语法:uuid()或uuid(sep)参数说明:sep布尔值,生成的uuid中是否包含分隔符'',缺省为
待兔 待兔
3个月前
手写Java HashMap源码
HashMap的使用教程HashMap的使用教程HashMap的使用教程HashMap的使用教程HashMap的使用教程22
Jacquelyn38 Jacquelyn38
3年前
2020年前端实用代码段,为你的工作保驾护航
有空的时候,自己总结了几个代码段,在开发中也经常使用,谢谢。1、使用解构获取json数据let jsonData  id: 1,status: "OK",data: 'a', 'b';let  id, status, data: number   jsonData;console.log(id, status, number )
Stella981 Stella981
3年前
DIY Ruby CPU 分析 Part II
【编者按】作者EmilSoman,Rubyist,除此之外竟然同时也是艺术家,吉他手,GardenCityRubyConf组织者。本文是DIYRubyCPUProfiling的第二部分。本文系OneAPM(https://www.oschina.net/action/GoToLink?urlhttp%3A%2F%2Fwww.one
Wesley13 Wesley13
3年前
mysql设置时区
mysql设置时区mysql\_query("SETtime\_zone'8:00'")ordie('时区设置失败,请联系管理员!');中国在东8区所以加8方法二:selectcount(user\_id)asdevice,CONVERT\_TZ(FROM\_UNIXTIME(reg\_time),'08:00','0
Stella981 Stella981
3年前
DIY Ruby CPU 分析——Part I
【编者按】原文作者EmilSoman,Rubyist,除此之外竟然同时也是_艺术家,吉他手_\\,GardenCityRubyConf组织者。本文是DIYRubyCPUProfiling的第一部分,由OneAPM(https://www.oschina.net/action/GoToLink?urlhttp%3A%2F%
Wesley13 Wesley13
3年前
00:Java简单了解
浅谈Java之概述Java是SUN(StanfordUniversityNetwork),斯坦福大学网络公司)1995年推出的一门高级编程语言。Java是一种面向Internet的编程语言。随着Java技术在web方面的不断成熟,已经成为Web应用程序的首选开发语言。Java是简单易学,完全面向对象,安全可靠,与平台无关的编程语言。
Wesley13 Wesley13
3年前
MySQL部分从库上面因为大量的临时表tmp_table造成慢查询
背景描述Time:20190124T00:08:14.70572408:00User@Host:@Id:Schema:sentrymetaLast_errno:0Killed:0Query_time:0.315758Lock_
Python进阶者 Python进阶者
9个月前
Excel中这日期老是出来00:00:00,怎么用Pandas把这个去除
大家好,我是皮皮。一、前言前几天在Python白银交流群【上海新年人】问了一个Pandas数据筛选的问题。问题如下:这日期老是出来00:00:00,怎么把这个去除。二、实现过程后来【论草莓如何成为冻干莓】给了一个思路和代码如下:pd.toexcel之前把这