¿Cuál es la diferencia entre tottime y cumtime en un script de python perfilado con cProfile?
cprofile python 3 (1)
Estoy perfilando un script de python main.py
usando cProfile con el siguiente comando:
python -m cProfile -s tottime main.py
La salida que obtengo es (solo copió y pegó las líneas superiores de la salida):
10184337 function calls (10181667 primitive calls) in 13.597 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
1 4.674 4.674 13.598 13.598 main.py:2(<module>)
2142 2.964 0.001 4.663 0.002 load_aerdat3.py:61(getPacket)
459 2.381 0.005 2.381 0.005 {waitKey}
1667989 1.170 0.000 1.170 0.000 {numpy.core.multiarray.array}
...
¿Cómo puede el tottime
(4.674) ser diferente del cumtime
(13.598) para main.py
, ya que esta función (es decir, el script completo) solo se llama una vez?
tottime
es el tiempo total empleado en la función solo . cumtime
es el tiempo total empleado en la función más todas las funciones a las que esta función llamó.
Los dos valores serán los mismos si una función nunca llama a nada más. Por ejemplo, {waitKey}
no parece invocar nada más:
459 2.381 0.005 2.381 0.005 {waitKey}
pero getPacket()
llama a otras funciones, por lo que su columna cumtime
incluye el tiempo para esas llamadas:
2142 2.964 0.001 4.663 0.002 load_aerdat3.py:61(getPacket)
La línea main.py
cubre todo el código ejecutado fuera de las funciones, el código global; solo las declaraciones en ese nivel tardaron 4,674 segundos en ejecutarse, pero debido a que esas declaraciones llamaban a otras funciones, el tiempo total acumulado del código main.py
más todas las llamadas a funciones realizadas es de 13,598 segundos.
De la documentation :
hora de verano
para el tiempo total empleado en la función dada (y excluyendo el tiempo realizado en llamadas a subfunciones)[...]
tiempo de corrida
es el tiempo acumulado empleado en esta y todas las subfunciones (desde la invocación hasta la salida). Esta cifra es precisa incluso para funciones recursivas.