Понимание вывода ruby-prof
Я запустил ruby-profiler на одной из моих программ. Я пытаюсь понять, что означает каждое поле. Я предполагаю, что все это время процессора (а не время настенных часов), что является фантастическим. Я хочу понять, что означает" - - -". Есть ли там какая-то информация о стеке. Что означает вызов 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!
--------------------------------------------------------------------------------
1 ответ:
каждый раздел вывода ruby-prof разбивается на рассмотрение конкретной функции. например, посмотрите на первый раздел вашего вывода. Метод read_frames на FrameParser-это фокус, и он в основном говорит следующее:
- 100% времени выполнения, которое было профилировано, было потрачено внутри FrameParser#read_frames
- FrameParser#read_frames был вызван 6 раз.
- 5 из 6 вызовов read_frames пришли из FrameParser#receive_data и это составляет 100% времени выполнения (это строка выше строки read_frames).
- строки ниже метода read_frames (но в этом первом разделе) - это все методы, которые FrameParser#read_frames вызывает (вы должны знать об этом, так как это похоже на ваш код), сколько из этих методов total calls read_frames отвечает за (столбец a/b calls) и сколько времени эти вызовы заняли. Им приказано, кто из них взял до самого времени исполнения. В вашем случае это метод receive_frame для класса ChatServer.
- затем вы можете посмотреть вниз на раздел, посвященный receive_frames (2 вниз и по центру с линией "100%" на receive_frame) и посмотреть, как это производительность разбивается. каждый раздел настроен таким же образом, и обычно последующий вызов функции, который занял больше всего времени, является фокусом следующего раздела вниз. ruby-prof будет продолжать делать это через полный стек вызовов. Ты можешь идти так глубоко, как вы хотите, пока не найдете узкое место, которое вы хотели бы решить.
Comments