How to track functions executions in real time?-CodePudding

The

CodePudding user response：

You can track function execution with sys.setprofile or sys.settrace - official documentation.

Here is a simple function profiler:

import os import sys import time from collections import defaultdict from datetime import datetime from types import FrameType import numpy as np CALL_STACK = defaultdict(list) def function_time_profiler(frame: FrameType, event: str, arg): # check possible options here https://docs.python.org/3/library/sys.html#sys.setprofile # now we are going to trace functions if event == "call": # where is the function is defined source_code_path = os.path.abspath(frame.f_code.co_filename) # by default all the functions are traced # including standard libs # now we skip tracing all functions from installed libraries # and tracing only user defined function # you may need to change this behaviour for your specific needs if not source_code_path.startswith(sys.prefix): function_name = frame.f_code.co_name func_key = f"{source_code_path}:{function_name}" current_time = datetime.now() # save the time at the moment of a call CALL_STACK[func_key].append(current_time) print(f"Calling function: '{func_key}' at {current_time}") # function exiting if event == "return": source_code_path = os.path.abspath(frame.f_code.co_filename) function_name = frame.f_code.co_name func_key = f"{source_code_path}:{function_name}" if func_key in CALL_STACK: # previously we saved the time when the function was called # so we can measure elapsed time func_start_time = CALL_STACK[func_key].pop() elapsed = (datetime.now() - func_start_time).total_seconds() print( f"Exiting function '{source_code_path}:{function_name}'. Execution time: {elapsed} seconds" ) return function_time_profiler def my_func_a(a): time.sleep(0.2) return a * a def my_func_b(a, b): s = 0 for _ in range(a): s = my_func_a(a) return a np.sqrt(b) # Start profiling sys.setprofile(function_time_profiler) r = my_func_b(5, 25) assert r == (0 1 2 4) 5 # Stop profiling sys.setprofile(None) sys.setprofile(function_time_profiler)

Results:

Calling function: '/home/u1234x1234/so/exp.py:my_func_b' at 2022-09-08 22:23:58.885964 Calling function: '/home/u1234x1234/so/exp.py:my_func_a' at 2022-09-08 22:23:58.885989 Exiting function '/home/u1234x1234/so/exp.py:my_func_a'. Execution time: 0.200249 seconds Calling function: '/home/u1234x1234/so/exp.py:my_func_a' at 2022-09-08 22:23:59.086269 Exiting function '/home/u1234x1234/so/exp.py:my_func_a'. Execution time: 0.200262 seconds Calling function: '/home/u1234x1234/so/exp.py:my_func_a' at 2022-09-08 22:23:59.286568 Exiting function '/home/u1234x1234/so/exp.py:my_func_a'. Execution time: 0.20027 seconds Calling function: '/home/u1234x1234/so/exp.py:my_func_a' at 2022-09-08 22:23:59.486873 Exiting function '/home/u1234x1234/so/exp.py:my_func_a'. Execution time: 0.200266 seconds Calling function: '/home/u1234x1234/so/exp.py:my_func_a' at 2022-09-08 22:23:59.687175 Exiting function '/home/u1234x1234/so/exp.py:my_func_a'. Execution time: 0.200265 seconds Exiting function '/home/u1234x1234/so/exp.py:my_func_b'. Execution time: 1.001529 seconds

Useful link: https://explog.in/notes/settrace.html