From 310b3d1b81d561e19d719acd89ee47b759e3795c Mon Sep 17 00:00:00 2001 From: Milan Rossa Date: Wed, 14 Aug 2019 16:09:36 +0200 Subject: [PATCH] py: Integrate sys.settrace feature into the VM and runtime. This commit adds support for sys.settrace, allowing to install Python handlers to trace execution of Python code. The interface follows CPython as closely as possible. The feature is disabled by default and can be enabled via MICROPY_PY_SYS_SETTRACE. --- ports/unix/main.c | 5 +++ ports/unix/mpconfigport.h | 4 ++ py/bc.c | 5 +++ py/bc.h | 18 ++++++++ py/compile.c | 6 +++ py/emitbc.c | 3 ++ py/emitglue.c | 15 +++++++ py/emitglue.h | 9 ++++ py/modsys.c | 17 ++++++++ py/mpconfig.h | 15 +++++++ py/mpstate.h | 6 +++ py/objfun.h | 3 ++ py/py.mk | 1 + py/runtime.c | 6 +++ py/vm.c | 89 ++++++++++++++++++++++++++++++++++++++- 15 files changed, 201 insertions(+), 1 deletion(-) diff --git a/ports/unix/main.c b/ports/unix/main.c index 65a4dd8a10..9147feb32d 100644 --- a/ports/unix/main.c +++ b/ports/unix/main.c @@ -655,7 +655,12 @@ MP_NOINLINE int main_(int argc, char **argv) { } } + #if MICROPY_PY_SYS_SETTRACE + MP_STATE_THREAD(prof_trace_callback) = MP_OBJ_NULL; + #endif + #if MICROPY_PY_SYS_ATEXIT + // Beware, the sys.settrace callback should be disabled before running sys.atexit. if (mp_obj_is_callable(MP_STATE_VM(sys_exitfunc))) { mp_call_function_0(MP_STATE_VM(sys_exitfunc)); } diff --git a/ports/unix/mpconfigport.h b/ports/unix/mpconfigport.h index 23c562e5aa..0ff6b2b06d 100644 --- a/ports/unix/mpconfigport.h +++ b/ports/unix/mpconfigport.h @@ -91,6 +91,10 @@ #define MICROPY_PY_BUILTINS_SLICE_ATTRS (1) #define MICROPY_PY_SYS_EXIT (1) #define MICROPY_PY_SYS_ATEXIT (1) +#if MICROPY_PY_SYS_SETTRACE +#define MICROPY_PERSISTENT_CODE_SAVE (1) +#define MICROPY_COMP_CONST (0) +#endif #if defined(__APPLE__) && defined(__MACH__) #define MICROPY_PY_SYS_PLATFORM "darwin" #else diff --git a/py/bc.c b/py/bc.c index b178e7c202..7d0b13bd74 100644 --- a/py/bc.c +++ b/py/bc.c @@ -119,6 +119,11 @@ void mp_setup_code_state(mp_code_state_t *code_state, size_t n_args, size_t n_kw code_state->prev = NULL; #endif + #if MICROPY_PY_SYS_SETTRACE + code_state->prev_state = NULL; + code_state->frame = NULL; + #endif + // get params size_t n_state = mp_decode_uint(&code_state->ip); code_state->ip = mp_decode_uint_skip(code_state->ip); // skip n_exc_stack diff --git a/py/bc.h b/py/bc.h index bedffa795e..ac9105a553 100644 --- a/py/bc.h +++ b/py/bc.h @@ -60,6 +60,20 @@ // const0 : obj // constN : obj +typedef struct _mp_bytecode_prelude_t { + uint n_state; + uint n_exc_stack; + uint scope_flags; + uint n_pos_args; + uint n_kwonly_args; + uint n_def_pos_args; + qstr qstr_block_name; + qstr qstr_source_file; + const byte *line_info; + const byte *locals; + const byte *opcodes; +} mp_bytecode_prelude_t; + // Exception stack entry typedef struct _mp_exc_stack_t { const byte *handler; @@ -84,6 +98,10 @@ typedef struct _mp_code_state_t { #if MICROPY_STACKLESS struct _mp_code_state_t *prev; #endif + #if MICROPY_PY_SYS_SETTRACE + struct _mp_code_state_t *prev_state; + struct _mp_obj_frame_t *frame; + #endif // Variable-length mp_obj_t state[0]; // Variable-length, never accessed by name, only as (void*)(state + n_state) diff --git a/py/compile.c b/py/compile.c index 41ff66a8ca..8b2d820b3b 100644 --- a/py/compile.c +++ b/py/compile.c @@ -1608,6 +1608,9 @@ STATIC void compile_try_except(compiler_t *comp, mp_parse_node_t pn_body, int n_ qstr qstr_exception_local = 0; uint end_finally_label = comp_next_label(comp); + #if MICROPY_PY_SYS_SETTRACE + EMIT_ARG(set_source_line, pns_except->source_line); + #endif if (MP_PARSE_NODE_IS_NULL(pns_except->nodes[0])) { // this is a catch all exception handler @@ -3157,6 +3160,9 @@ STATIC void compile_scope(compiler_t *comp, scope_t *scope, pass_kind_t pass) { scope_find_or_add_id(scope, MP_QSTR___class__, ID_INFO_KIND_LOCAL); } + #if MICROPY_PY_SYS_SETTRACE + EMIT_ARG(set_source_line, pns->source_line); + #endif compile_load_id(comp, MP_QSTR___name__); compile_store_id(comp, MP_QSTR___module__); EMIT_ARG(load_const_str, MP_PARSE_NODE_LEAF_ARG(pns->nodes[0])); // 0 is class name diff --git a/py/emitbc.c b/py/emitbc.c index fcbd979d27..ef0d20a102 100644 --- a/py/emitbc.c +++ b/py/emitbc.c @@ -284,6 +284,9 @@ STATIC void emit_write_bytecode_byte_raw_code(emit_t *emit, int stack_adj, byte assert(c == MP_ALIGN(c, sizeof(void*))); *c = rc; #endif + #if MICROPY_PY_SYS_SETTRACE + rc->line_of_definition = emit->last_source_line; + #endif } // unsigned labels are relative to ip following this instruction, stored as 16 bits diff --git a/py/emitglue.c b/py/emitglue.c index 483a47025b..d30a1e6741 100644 --- a/py/emitglue.c +++ b/py/emitglue.c @@ -34,6 +34,7 @@ #include "py/emitglue.h" #include "py/runtime0.h" #include "py/bc.h" +#include "py/profile.h" #if MICROPY_DEBUG_VERBOSE // print debugging info #define DEBUG_PRINT (1) @@ -52,6 +53,9 @@ mp_uint_t mp_verbose_flag = 0; mp_raw_code_t *mp_emit_glue_new_raw_code(void) { mp_raw_code_t *rc = m_new0(mp_raw_code_t, 1); rc->kind = MP_CODE_RESERVED; + #if MICROPY_PY_SYS_SETTRACE + rc->line_of_definition = 0; + #endif return rc; } @@ -75,6 +79,11 @@ void mp_emit_glue_assign_bytecode(mp_raw_code_t *rc, const byte *code, rc->n_raw_code = n_raw_code; #endif + #if MICROPY_PY_SYS_SETTRACE + mp_bytecode_prelude_t *prelude = &rc->prelude; + mp_prof_extract_prelude(code, prelude); + #endif + #ifdef DEBUG_PRINT #if !MICROPY_DEBUG_PRINTERS const size_t len = 0; @@ -172,6 +181,12 @@ mp_obj_t mp_make_function_from_raw_code(const mp_raw_code_t *rc, mp_obj_t def_ar if ((rc->scope_flags & MP_SCOPE_FLAG_GENERATOR) != 0) { ((mp_obj_base_t*)MP_OBJ_TO_PTR(fun))->type = &mp_type_gen_wrap; } + + #if MICROPY_PY_SYS_SETTRACE + mp_obj_fun_bc_t *self_fun = (mp_obj_fun_bc_t *)MP_OBJ_TO_PTR(fun); + self_fun->rc = rc; + #endif + break; } diff --git a/py/emitglue.h b/py/emitglue.h index b67d49ed6d..a5411dc2e2 100644 --- a/py/emitglue.h +++ b/py/emitglue.h @@ -27,6 +27,7 @@ #define MICROPY_INCLUDED_PY_EMITGLUE_H #include "py/obj.h" +#include "py/bc.h" // These variables and functions glue the code emitters to the runtime. @@ -63,6 +64,14 @@ typedef struct _mp_raw_code_t { size_t fun_data_len; uint16_t n_obj; uint16_t n_raw_code; + #if MICROPY_PY_SYS_SETTRACE + mp_bytecode_prelude_t prelude; + // line_of_definition is a Python source line where the raw_code was + // created e.g. MP_BC_MAKE_FUNCTION. This is different from lineno info + // stored in prelude, which provides line number for first statement of + // a function. Required to properly implement "call" trace event. + mp_uint_t line_of_definition; + #endif #if MICROPY_EMIT_MACHINE_CODE uint16_t prelude_offset; uint16_t n_qstr; diff --git a/py/modsys.c b/py/modsys.c index 3a91393812..4886419d0e 100644 --- a/py/modsys.c +++ b/py/modsys.c @@ -35,6 +35,11 @@ #include "py/smallint.h" #include "py/runtime.h" +#if MICROPY_PY_SYS_SETTRACE +#include "py/objmodule.h" +#include "py/profile.h" +#endif + #if MICROPY_PY_SYS // defined per port; type of these is irrelevant, just need pointer @@ -156,6 +161,14 @@ STATIC mp_obj_t mp_sys_atexit(mp_obj_t obj) { STATIC MP_DEFINE_CONST_FUN_OBJ_1(mp_sys_atexit_obj, mp_sys_atexit); #endif +#if MICROPY_PY_SYS_SETTRACE +// settrace(tracefunc): Set the system’s trace function. +STATIC mp_obj_t mp_sys_settrace(mp_obj_t obj) { + return mp_prof_settrace(obj); +} +MP_DEFINE_CONST_FUN_OBJ_1(mp_sys_settrace_obj, mp_sys_settrace); +#endif // MICROPY_PY_SYS_SETTRACE + STATIC const mp_rom_map_elem_t mp_module_sys_globals_table[] = { { MP_ROM_QSTR(MP_QSTR___name__), MP_ROM_QSTR(MP_QSTR_sys) }, @@ -190,6 +203,10 @@ STATIC const mp_rom_map_elem_t mp_module_sys_globals_table[] = { { MP_ROM_QSTR(MP_QSTR_exit), MP_ROM_PTR(&mp_sys_exit_obj) }, #endif + #if MICROPY_PY_SYS_SETTRACE + { MP_ROM_QSTR(MP_QSTR_settrace), MP_ROM_PTR(&mp_sys_settrace_obj) }, + #endif + #if MICROPY_PY_SYS_STDFILES { MP_ROM_QSTR(MP_QSTR_stdin), MP_ROM_PTR(&mp_sys_stdin_obj) }, { MP_ROM_QSTR(MP_QSTR_stdout), MP_ROM_PTR(&mp_sys_stdout_obj) }, diff --git a/py/mpconfig.h b/py/mpconfig.h index 57dec3cf26..64dadde92d 100644 --- a/py/mpconfig.h +++ b/py/mpconfig.h @@ -1171,6 +1171,11 @@ typedef double mp_float_t; #define MICROPY_PY_SYS_ATEXIT (0) #endif +// Whether to provide "sys.settrace" function +#ifndef MICROPY_PY_SYS_SETTRACE +#define MICROPY_PY_SYS_SETTRACE (0) +#endif + // Whether to provide "sys.getsizeof" function #ifndef MICROPY_PY_SYS_GETSIZEOF #define MICROPY_PY_SYS_GETSIZEOF (0) @@ -1571,4 +1576,14 @@ typedef double mp_float_t; # define MP_WARN_CAT(x) (NULL) #endif +// Feature dependency check. +#if MICROPY_PY_SYS_SETTRACE +#if !MICROPY_PERSISTENT_CODE_SAVE +#error "MICROPY_PY_SYS_SETTRACE requires MICROPY_PERSISTENT_CODE_SAVE to be enabled" +#endif +#if MICROPY_COMP_CONST +#error "MICROPY_PY_SYS_SETTRACE requires MICROPY_COMP_CONST to be disabled" +#endif +#endif + #endif // MICROPY_INCLUDED_PY_MPCONFIG_H diff --git a/py/mpstate.h b/py/mpstate.h index 83fea3eb41..aba32084d5 100644 --- a/py/mpstate.h +++ b/py/mpstate.h @@ -253,6 +253,12 @@ typedef struct _mp_state_thread_t { mp_obj_dict_t *dict_globals; nlr_buf_t *nlr_top; + + #if MICROPY_PY_SYS_SETTRACE + mp_obj_t prof_trace_callback; + bool prof_callback_is_executing; + struct _mp_code_state_t *current_code_state; + #endif } mp_state_thread_t; // This structure combines the above 3 structures. diff --git a/py/objfun.h b/py/objfun.h index 257b8a65a7..905b5dbca6 100644 --- a/py/objfun.h +++ b/py/objfun.h @@ -33,6 +33,9 @@ typedef struct _mp_obj_fun_bc_t { mp_obj_dict_t *globals; // the context within which this function was defined const byte *bytecode; // bytecode for the function const mp_uint_t *const_table; // constant table + #if MICROPY_PY_SYS_SETTRACE + const struct _mp_raw_code_t *rc; + #endif // the following extra_args array is allocated space to take (in order): // - values of positional default args (if any) // - a single slot for default kw args dict (if it has them) diff --git a/py/py.mk b/py/py.mk index 10beb29e45..d60e694ec2 100644 --- a/py/py.mk +++ b/py/py.mk @@ -86,6 +86,7 @@ PY_CORE_O_BASENAME = $(addprefix py/,\ stackctrl.o \ argcheck.o \ warning.o \ + profile.o \ map.o \ obj.o \ objarray.o \ diff --git a/py/runtime.c b/py/runtime.c index d81321e862..ecbdff2bab 100644 --- a/py/runtime.c +++ b/py/runtime.c @@ -125,6 +125,12 @@ void mp_init(void) { MP_STATE_VM(sys_exitfunc) = mp_const_none; #endif + #if MICROPY_PY_SYS_SETTRACE + MP_STATE_THREAD(prof_trace_callback) = MP_OBJ_NULL; + MP_STATE_THREAD(prof_callback_is_executing) = false; + MP_STATE_THREAD(current_code_state) = NULL; + #endif + #if MICROPY_PY_THREAD_GIL mp_thread_mutex_init(&MP_STATE_VM(gil_mutex)); #endif diff --git a/py/vm.c b/py/vm.c index 0bc2034613..9abad8d83f 100644 --- a/py/vm.c +++ b/py/vm.c @@ -34,6 +34,7 @@ #include "py/runtime.h" #include "py/bc0.h" #include "py/bc.h" +#include "py/profile.h" #if 0 #define TRACE(ip) printf("sp=%d ", (int)(sp - &code_state->state[0] + 1)); mp_bytecode_print2(ip, 1, code_state->fun_bc->const_table); @@ -108,6 +109,55 @@ exc_sp--; /* pop back to previous exception handler */ \ CLEAR_SYS_EXC_INFO() /* just clear sys.exc_info(), not compliant, but it shouldn't be used in 1st place */ +#if MICROPY_PY_SYS_SETTRACE + +#define FRAME_SETUP() do { \ + assert(code_state != code_state->prev_state); \ + MP_STATE_THREAD(current_code_state) = code_state; \ + assert(code_state != code_state->prev_state); \ +} while(0) + +#define FRAME_ENTER() do { \ + assert(code_state != code_state->prev_state); \ + code_state->prev_state = MP_STATE_THREAD(current_code_state); \ + assert(code_state != code_state->prev_state); \ + if (!mp_prof_is_executing) { \ + mp_prof_frame_enter(code_state); \ + } \ +} while(0) + +#define FRAME_LEAVE() do { \ + assert(code_state != code_state->prev_state); \ + MP_STATE_THREAD(current_code_state) = code_state->prev_state; \ + assert(code_state != code_state->prev_state); \ +} while(0) + +#define FRAME_UPDATE() do { \ + assert(MP_STATE_THREAD(current_code_state) == code_state); \ + if (!mp_prof_is_executing) { \ + code_state->frame = MP_OBJ_TO_PTR(mp_prof_frame_update(code_state)); \ + } \ +} while(0) + +#define TRACE_TICK(current_ip, current_sp, is_exception) do { \ + assert(code_state != code_state->prev_state); \ + assert(MP_STATE_THREAD(current_code_state) == code_state); \ + if (!mp_prof_is_executing && code_state->frame && MP_STATE_THREAD(prof_trace_callback)) { \ + MP_PROF_INSTR_DEBUG_PRINT(code_state->ip); \ + } \ + if (!mp_prof_is_executing && code_state->frame && code_state->frame->callback) { \ + mp_prof_instr_tick(code_state, is_exception); \ + } \ +} while(0) + +#else // MICROPY_PY_SYS_SETTRACE +#define FRAME_SETUP() +#define FRAME_ENTER() +#define FRAME_LEAVE() +#define FRAME_UPDATE() +#define TRACE_TICK(current_ip, current_sp, is_exception) +#endif // MICROPY_PY_SYS_SETTRACE + // fastn has items in reverse order (fastn[0] is local[0], fastn[-1] is local[1], etc) // sp points to bottom of stack which grows up // returns: @@ -128,6 +178,7 @@ mp_vm_return_kind_t mp_execute_bytecode(mp_code_state_t *code_state, volatile mp #define DISPATCH() do { \ TRACE(ip); \ MARK_EXC_IP_GLOBAL(); \ + TRACE_TICK(ip, sp, false); \ goto *entry_table[*ip++]; \ } while (0) #define DISPATCH_WITH_PEND_EXC_CHECK() goto pending_exception_check @@ -149,6 +200,13 @@ mp_vm_return_kind_t mp_execute_bytecode(mp_code_state_t *code_state, volatile mp #if MICROPY_STACKLESS run_code_state: ; #endif +FRAME_ENTER(); + +#if MICROPY_STACKLESS +run_code_state_from_return: ; +#endif +FRAME_SETUP(); + // Pointers which are constant for particular invocation of mp_execute_bytecode() mp_obj_t * /*const*/ fastn; mp_exc_stack_t * /*const*/ exc_stack; @@ -198,6 +256,7 @@ dispatch_loop: #else TRACE(ip); MARK_EXC_IP_GLOBAL(); + TRACE_TICK(ip, sp, false); switch (*ip++) { #endif @@ -323,6 +382,7 @@ dispatch_loop: #if !MICROPY_OPT_CACHE_MAP_LOOKUP_IN_BYTECODE ENTRY(MP_BC_LOAD_ATTR): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_QSTR; SET_TOP(mp_load_attr(TOP(), qst)); @@ -330,6 +390,7 @@ dispatch_loop: } #else ENTRY(MP_BC_LOAD_ATTR): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_QSTR; mp_obj_t top = TOP(); @@ -415,6 +476,7 @@ dispatch_loop: #if !MICROPY_OPT_CACHE_MAP_LOOKUP_IN_BYTECODE ENTRY(MP_BC_STORE_ATTR): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_QSTR; mp_store_attr(sp[0], qst, sp[-1]); @@ -428,6 +490,7 @@ dispatch_loop: // consequence of this is that we can't use MP_MAP_LOOKUP_ADD_IF_NOT_FOUND // in the fast-path below, because that store could override a property. ENTRY(MP_BC_STORE_ATTR): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_QSTR; mp_obj_t top = TOP(); @@ -738,6 +801,7 @@ unwind_jump:; } ENTRY(MP_BC_FOR_ITER): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_ULABEL; // the jump offset if iteration finishes; for labels are always forward code_state->sp = sp; @@ -753,6 +817,12 @@ unwind_jump:; ip += ulab; // jump to after for-block } else { PUSH(value); // push the next iteration value + #if MICROPY_PY_SYS_SETTRACE + // LINE event should trigger for every iteration so invalidate last trigger + if (code_state->frame) { + code_state->frame->lineno = 0; + } + #endif } DISPATCH(); } @@ -887,6 +957,7 @@ unwind_jump:; } ENTRY(MP_BC_CALL_FUNCTION): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_UINT; // unum & 0xff == n_positional @@ -921,6 +992,7 @@ unwind_jump:; } ENTRY(MP_BC_CALL_FUNCTION_VAR_KW): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_UINT; // unum & 0xff == n_positional @@ -966,6 +1038,7 @@ unwind_jump:; } ENTRY(MP_BC_CALL_METHOD): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_UINT; // unum & 0xff == n_positional @@ -1004,6 +1077,7 @@ unwind_jump:; } ENTRY(MP_BC_CALL_METHOD_VAR_KW): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_UINT; // unum & 0xff == n_positional @@ -1096,9 +1170,10 @@ unwind_return: #endif code_state = new_code_state; *code_state->sp = res; - goto run_code_state; + goto run_code_state_from_return; } #endif + FRAME_LEAVE(); return MP_VM_RETURN_NORMAL; ENTRY(MP_BC_RAISE_VARARGS): { @@ -1136,6 +1211,7 @@ yield: code_state->ip = ip; code_state->sp = sp; code_state->exc_sp = MP_TAGPTR_MAKE(exc_sp, 0); + FRAME_LEAVE(); return MP_VM_RETURN_YIELD; ENTRY(MP_BC_YIELD_FROM): { @@ -1192,6 +1268,7 @@ yield: } ENTRY(MP_BC_IMPORT_NAME): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_QSTR; mp_obj_t obj = POP(); @@ -1200,6 +1277,7 @@ yield: } ENTRY(MP_BC_IMPORT_FROM): { + FRAME_UPDATE(); MARK_EXC_IP_SELECTIVE(); DECODE_QSTR; mp_obj_t obj = mp_import_from(TOP(), qst); @@ -1266,6 +1344,7 @@ yield: mp_obj_t obj = mp_obj_new_exception_msg(&mp_type_NotImplementedError, "opcode"); nlr_pop(); code_state->state[0] = obj; + FRAME_LEAVE(); return MP_VM_RETURN_EXCEPTION; } @@ -1356,6 +1435,13 @@ exception_handler: } } + #if MICROPY_PY_SYS_SETTRACE + // Exceptions are traced here + if (mp_obj_is_subclass_fast(MP_OBJ_FROM_PTR(((mp_obj_base_t*)nlr.ret_val)->type), MP_OBJ_FROM_PTR(&mp_type_Exception))) { + TRACE_TICK(code_state->ip, code_state->sp, true /* yes, it's an exception */); + } + #endif + #if MICROPY_STACKLESS unwind_loop: #endif @@ -1438,6 +1524,7 @@ unwind_loop: // propagate exception to higher level // Note: ip and sp don't have usable values at this point code_state->state[0] = MP_OBJ_FROM_PTR(nlr.ret_val); // put exception here because sp is invalid + FRAME_LEAVE(); return MP_VM_RETURN_EXCEPTION; } }