I also using an android trace visualization https://ui.perfetto.dev/#!/ that takes a json data like {"name":foo, "time start":0.1, "duration":0.4} and generates a cool interactive visualizations.
It is easy generate such data from trace events, but my problem appears with asyncio programs.
Does anyone know how to use traces to calculate task_A/B running time?
Code: Select all
import time
import sys # Build mpy with MICROPY_PY_SYS_SETTRACE 1 to enable sys.settrace feature
import uasyncio as asyncio
def _print( *kw ): # built in print wrapper to allow trace
print( *kw )
async def task_A():
_print( "A", "Hello" )
await asyncio.sleep( 0.4 )
_print( "A", "World" )
async def task_B():
_print( "B", "Hello" )
await asyncio.sleep( 0.1 )
_print( "B", "World" )
async def main():
asyncio.create_task( task_A() )
asyncio.create_task( task_B() )
await asyncio.sleep( 0.5 )
def trace_tick_handler( frame, event, arg ):
global t0, traces
if( event != "line" ):
t = time.ticks_us()-t0
func_name = frame.f_code.co_name
func_line_no = frame.f_lineno
func_filename = frame.f_code.co_filename
caller = frame.f_back
caller_line_no = caller.f_lineno
caller_filename = caller.f_code.co_filename
traces += [(t, (func_name, func_line_no, func_filename, caller_line_no, caller_filename), event, arg)]
return trace_tick_handler
print( "done" )
traces = []
t0 = time.ticks_us()
print( "Enable traces")
sys.settrace( trace_tick_handler )
asyncio.run( main() )
asyncio.new_event_loop()
sys.settrace( None )
print( "Disable traces" )
print( "len( traces )", len( traces ) )
print( "done" )
for i, trace in enumerate( traces ):
print( i, trace )
Code: Select all
text_start = """{
"displayTimeUnit": "ns",
"traceEvents": [
{"args": {"name": "MainProcess"},"name": "process_name","ph": "M","pid": 1111,"tid": 1111},
{"args": {"name": "MainThread"},"name": "thread_name","ph": "M","pid": 1111,"tid": 2222},"""
text_end = """ ]
}
"""
event_template = {
"caller_lineno": 1,
"cat": "FEE",
"dur": 1,
"name": "foo (C:\\program.py:1)",
"ph": "X",
"pid": 1111,
"tid": 2222,
"ts": 1
}
print( text_start )
ts = []
caller_lineno = []
name = []
for trace in traces:
t, frame, event, arg = trace
func_name, func_line_no, func_filename, caller_line_no, caller_filename = frame
if( event == "call" ):
ts += [t]
if( event == "return" ):
event = dict( event_template )
event["caller_lineno"] = caller_line_no
event["name"] = func_name + " " + "(" + func_filename + ":" + str( func_line_no ) + ")"
event["ts"] = ts.pop()
event["dur"] = t - event["ts"]
print( " " + str( event ).replace( "'","\"" ), end="" )
if( trace != traces[-1] ):
print( "," )
else:
print( "" )
print( text_end )
But still is wrong.
How can I interpret asyncio __iter__/__next__/wait_io_event call/return/exception as different threads?
Note: If you dont need asyncio, enable traces and visualize with perfetto its amazing to visualize how ur micropython program execution!