60

我在我的一个程序上运行了 ruby​​-profiler。我试图弄清楚每个字段的含义。我猜一切都是 CPU 时间(而不是挂钟时间),这太棒了。我想了解“---”代表什么。那里是否有某种堆栈信息。调用 a/b 是什么意思?

Thread ID: 81980260
Total Time: 0.28

  %total   %self     total      self      wait     child            calls   Name
--------------------------------------------------------------------------------
                      0.28      0.00      0.00      0.28              5/6     FrameParser#receive_data
 100.00%   0.00%      0.28      0.00      0.00      0.28                6     FrameParser#read_frames
                      0.28      0.00      0.00      0.28              4/4     ChatServerClient#receive_frame
                      0.00      0.00      0.00      0.00             5/47     Fixnum#+
                      0.00      0.00      0.00      0.00              1/2     DebugServer#receive_frame
                      0.00      0.00      0.00      0.00            10/29     String#[]
                      0.00      0.00      0.00      0.00            10/21     <Class::Range>#allocate
                      0.00      0.00      0.00      0.00            10/71     String#index
--------------------------------------------------------------------------------
 100.00%   0.00%      0.28      0.00      0.00      0.28                5     FrameParser#receive_data
                      0.28      0.00      0.00      0.28              5/6     FrameParser#read_frames
                      0.00      0.00      0.00      0.00             5/16     ActiveSupport::CoreExtensions::String::OutputSafety#add_with_safety
--------------------------------------------------------------------------------
                      0.28      0.00      0.00      0.28              4/4     FrameParser#read_frames
 100.00%   0.00%      0.28      0.00      0.00      0.28                4     ChatServerClient#receive_frame
                      0.28      0.00      0.00      0.28              4/6     <Class::Lal>#safe_call
--------------------------------------------------------------------------------
                      0.00      0.00      0.00      0.00              1/6     <Class::Lal>#safe_call
                      0.00      0.00      0.00      0.00              1/6     DebugServer#receive_frame
                      0.28      0.00      0.00      0.28              4/6     ChatServerClient#receive_frame
 100.00%   0.00%      0.28      0.00      0.00      0.28                6     <Class::Lal>#safe_call
                      0.21      0.00      0.00      0.21              2/4     ChatUserFunction#register
                      0.06      0.00      0.00      0.06              2/2     ChatUserFunction#packet
                      0.01      0.00      0.00      0.01            4/130     Class#new
                      0.00      0.00      0.00      0.00              1/1     DebugServer#profile_stop
                      0.00      0.00      0.00      0.00             1/33     String#==
                      0.00      0.00      0.00      0.00              1/6     <Class::Lal>#safe_call
                      0.00      0.00      0.00      0.00              5/5     JSON#parse
                      0.00      0.00      0.00      0.00              5/8     <Class::Log>#log
                      0.00      0.00      0.00      0.00              5/5     String#strip!
--------------------------------------------------------------------------------
4

1 回答 1

68

ruby-prof 输出的每个部分都被分解为对特定函数的检查。例如,查看输出的第一部分。FrameParser 上的 read_frames 方法是重点,它基本上是在说以下内容:

  • 所分析的 100% 的执行时间都花在了 FrameParser#read_frames 中
  • FrameParser#read_frames 被调用了 6 次。
  • 5 out of the 6 calls to read_frames came from FrameParser#receive_data and this accounted 100% of the execution time (this is the line above the read_frames line).
  • The lines below the read_frames (but within that first section) method are all of the methods that FrameParser#read_frames calls (you should be aware of that since this seems like it's your code), how many of that methods total calls read_frames is responsible for (the a/b calls column), and how much time those calls took. They are ordered by which of them took up the most execution time. In your case, that is receive_frame method on the ChatServer class.
  • 然后,您可以查看专注于receive_frames 的部分(向下2 并以receive_frame 上的“100%”线为中心),看看它的性能是如何分解的。每个部分都以相同的方式设置,通常花费最多时间的后续函数调用是下一部分的重点。ruby-prof 将通过完整的调用堆栈继续执行此操作。您可以随心所欲地深入,直到找到您想要解决的瓶颈。
于 2011-03-20T03:25:04.043 回答