Comprender la salida de Ruby-prof

Question

Ejecuto ruby-profiler en uno de mis programas. Estoy tratando de averiguar qué significa cada campo. Supongo que todo es tiempo de CPU (y no de reloj de pared), lo cual es fantástico. Quiero entender qué significa "---". ¿Hay algún tipo de información de pila allí? ¿Qué significa llamadas 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! 
-------------------------------------------------------------------------------- 

Answer 1

Cada sección de la salida de ruby-prof se divide en el examen de una función particular. por ejemplo, mira la primera sección de tu salida. El método read_frames en FrameParser es el foco y que básicamente está diciendo lo siguiente:

• 100% del tiempo de ejecución que se perfila se gastó en el interior de FrameParser # read_frames
• FrameParser # read_frames fue llamado 6 veces.
• 5 de las 6 llamadas a read_frames provenían de FrameParser # receive_data y esto representaba el 100% del tiempo de ejecución (esta es la línea sobre la línea read_frames).
• Las líneas debajo del método read_frames (pero dentro de esa primera sección) son todos los métodos que llama FrameParser # read_frames (debe tener en cuenta que, dado que esto parece ser su código), cuántos de esos métodos totalizan las llamadas read_frames es responsable de (la columna de llamadas a/b) y cuánto tiempo tomaron esas llamadas. Están ordenados por cuál de ellos tomó el mayor tiempo de ejecución. En su caso, ese es el método receive_frame en la clase ChatServer.
• A continuación, puede mirar la sección que se enfoca en los recuadros de recepción (2 abajo y centrado con la línea '100%' en el recuadro de recepción) y ver cómo se desglosa el rendimiento. cada sección está configurada de la misma manera y, por lo general, la siguiente llamada de función que tomó más tiempo es el foco de la siguiente sección. ruby-prof continuará haciendo esto a través de la pila de llamadas completa. Puede ir tan profundo como desee hasta que encuentre el cuello de botella que le gustaría resolver.