diff --git a/lib/libesp32/Berry/default/berry_conf.h b/lib/libesp32/Berry/default/berry_conf.h index 2514013b9..3360b9082 100644 --- a/lib/libesp32/Berry/default/berry_conf.h +++ b/lib/libesp32/Berry/default/berry_conf.h @@ -71,6 +71,21 @@ **/ #define BE_USE_OBSERVABILITY_HOOK 1 +/* Macro: BE_USE_OBSERVABILITY_HOOK + * Use the obshook function to report low-level actions. + * Default: 0 + **/ +#define BE_USE_PERF_COUNTERS 1 + +/* Macro: BE_VM_OBSERVABILITY_SAMPLING + * If BE_USE_OBSERVABILITY_HOOK == 1 and BE_USE_PERF_COUNTERS == 1 + * then the observability hook is called regularly in the VM loop + * allowing to stop infinite loops or too-long running code. + * The value is a power of 2. + * Default: 20 - which translates to 2^20 or ~1 million instructions + **/ +#define BE_VM_OBSERVABILITY_SAMPLING 20 + /* Macro: BE_STACK_TOTAL_MAX * Set the maximum total stack size. * Default: 20000 diff --git a/lib/libesp32/Berry/generate/be_const_strtab.h b/lib/libesp32/Berry/generate/be_const_strtab.h index 18b105034..051a74990 100644 --- a/lib/libesp32/Berry/generate/be_const_strtab.h +++ b/lib/libesp32/Berry/generate/be_const_strtab.h @@ -73,6 +73,7 @@ extern const bcstring be_const_str_select; extern const bcstring be_const_str_BOILER_OT_TX; extern const bcstring be_const_str_INPUT_PULLDOWN; extern const bcstring be_const_str_WEBCAM_SIOC; +extern const bcstring be_const_str_counters; extern const bcstring be_const_str_resp_cmnd_done; extern const bcstring be_const_str_tob64; extern const bcstring be_const_str_response_append; diff --git a/lib/libesp32/Berry/generate/be_const_strtab_def.h b/lib/libesp32/Berry/generate/be_const_strtab_def.h index 2c04ee61a..daaaa0eab 100644 --- a/lib/libesp32/Berry/generate/be_const_strtab_def.h +++ b/lib/libesp32/Berry/generate/be_const_strtab_def.h @@ -72,7 +72,8 @@ be_define_const_str(cos, "cos", 4220379804u, 0, 3, &be_const_str_select); be_define_const_str(select, "select", 297952813u, 0, 6, NULL); be_define_const_str(BOILER_OT_TX, "BOILER_OT_TX", 671743623u, 0, 12, &be_const_str_INPUT_PULLDOWN); be_define_const_str(INPUT_PULLDOWN, "INPUT_PULLDOWN", 1172232591u, 0, 14, &be_const_str_WEBCAM_SIOC); -be_define_const_str(WEBCAM_SIOC, "WEBCAM_SIOC", 218815147u, 0, 11, &be_const_str_resp_cmnd_done); +be_define_const_str(WEBCAM_SIOC, "WEBCAM_SIOC", 218815147u, 0, 11, &be_const_str_counters); +be_define_const_str(counters, "counters", 4095866864u, 0, 8, &be_const_str_resp_cmnd_done); be_define_const_str(resp_cmnd_done, "resp_cmnd_done", 2601874875u, 0, 14, &be_const_str_tob64); be_define_const_str(tob64, "tob64", 373777640u, 0, 5, NULL); be_define_const_str(response_append, "response_append", 450346371u, 0, 15, NULL); @@ -887,6 +888,6 @@ static const bstring* const m_string_table[] = { static const struct bconststrtab m_const_string_table = { .size = 287, - .count = 574, + .count = 575, .table = m_string_table }; diff --git a/lib/libesp32/Berry/generate/be_fixed_debug.h b/lib/libesp32/Berry/generate/be_fixed_debug.h index d6ab2709c..ef3b32236 100644 --- a/lib/libesp32/Berry/generate/be_fixed_debug.h +++ b/lib/libesp32/Berry/generate/be_fixed_debug.h @@ -1,16 +1,17 @@ #include "be_constobj.h" static be_define_const_map_slots(m_libdebug_map) { + { be_const_key(counters, 3), be_const_func(m_counters) }, { be_const_key(traceback, -1), be_const_func(m_traceback) }, - { be_const_key(codedump, -1), be_const_func(m_codedump) }, - { be_const_key(calldepth, -1), be_const_func(m_calldepth) }, - { be_const_key(top, -1), be_const_func(m_top) }, { be_const_key(attrdump, 0), be_const_func(m_attrdump) }, + { be_const_key(calldepth, 5), be_const_func(m_calldepth) }, + { be_const_key(top, -1), be_const_func(m_top) }, + { be_const_key(codedump, -1), be_const_func(m_codedump) }, }; static be_define_const_map( m_libdebug_map, - 5 + 6 ); static be_define_const_module( diff --git a/lib/libesp32/Berry/src/be_debuglib.c b/lib/libesp32/Berry/src/be_debuglib.c index 9989da064..13c15f50e 100644 --- a/lib/libesp32/Berry/src/be_debuglib.c +++ b/lib/libesp32/Berry/src/be_debuglib.c @@ -149,6 +149,31 @@ static int m_upvname(bvm *vm) } #endif + +#if BE_USE_PERF_COUNTERS +static void map_insert(bvm *vm, const char *key, int value) +{ + be_pushstring(vm, key); + be_pushint(vm, value); + be_data_insert(vm, -3); + be_pop(vm, 2); +} + +static int m_counters(bvm *vm) +{ + be_newobject(vm, "map"); + map_insert(vm, "instruction", vm->counter_ins); + map_insert(vm, "vmenter", vm->counter_enter); + map_insert(vm, "call", vm->counter_call); + map_insert(vm, "get", vm->counter_get); + map_insert(vm, "set", vm->counter_set); + map_insert(vm, "try", vm->counter_try); + map_insert(vm, "raise", vm->counter_exc); + be_pop(vm, 1); + be_return(vm); +} +#endif + #if !BE_USE_PRECOMPILED_OBJECT be_native_module_attr_table(debug) { be_native_module_function("attrdump", m_attrdump), @@ -156,6 +181,9 @@ be_native_module_attr_table(debug) { be_native_module_function("traceback", m_traceback), #if BE_USE_DEBUG_HOOK be_native_module_function("sethook", m_sethook), +#endif +#if BE_USE_PERF_COUNTERS + be_native_module_function("counters", m_counters), #endif be_native_module_function("calldepth", m_calldepth), be_native_module_function("top", m_top), @@ -173,6 +201,7 @@ module debug (scope: global, depend: BE_USE_DEBUG_MODULE) { codedump, func(m_codedump) traceback, func(m_traceback) sethook, func(m_sethook), BE_USE_DEBUG_HOOK + counters, func(m_counters), BE_USE_PERF_COUNTERS calldepth, func(m_calldepth) top, func(m_top) varname, func(m_varname), BE_DEBUG_VAR_INFO diff --git a/lib/libesp32/Berry/src/be_vm.c b/lib/libesp32/Berry/src/be_vm.c index 915977cda..3d9d2db4d 100644 --- a/lib/libesp32/Berry/src/be_vm.c +++ b/lib/libesp32/Berry/src/be_vm.c @@ -48,9 +48,28 @@ #define DEBUG_HOOK() #endif +#if BE_USE_PERF_COUNTERS + #define COUNTER_HOOK() \ + vm->counter_ins++; +#else + #define COUNTER_HOOK() +#endif + +#if BE_USE_PERF_COUNTERS && BE_USE_OBSERVABILITY_HOOK + #define VM_HEARTBEAT() \ + if ((vm->counter_ins & ((1<<(BE_VM_OBSERVABILITY_SAMPLING - 1))-1) ) == 0) { /* call every 2^BE_VM_OBSERVABILITY_SAMPLING instructions */ \ + if (vm->obshook != NULL) \ + (*vm->obshook)(vm, BE_OBS_VM_HEARTBEAT, vm->counter_ins); \ + } +#else + #define VM_HEARTBEAT() +#endif + #define vm_exec_loop() \ loop: \ DEBUG_HOOK(); \ + COUNTER_HOOK(); \ + VM_HEARTBEAT(); \ switch (IGET_OP(ins = *vm->ip++)) #if BE_USE_SINGLE_FLOAT @@ -444,6 +463,15 @@ BERRY_API bvm* be_vm_new(void) vm->compopt = 0; #if BE_USE_OBSERVABILITY_HOOK vm->obshook = NULL; +#endif +#if BE_USE_PERF_COUNTERS + vm->counter_ins = 0; + vm->counter_enter = 0; + vm->counter_call = 0; + vm->counter_get = 0; + vm->counter_set = 0; + vm->counter_try = 0; + vm->counter_exc = 0; #endif return vm; } @@ -478,6 +506,9 @@ newframe: /* a new call frame */ clos = var_toobj(vm->cf->func); /* `clos` is the current function/closure */ ktab = clos->proto->ktab; /* `ktab` is the current constant table */ reg = vm->reg; /* `reg` is the current stack base for the callframe */ +#if BE_USE_PERF_COUNTERS + vm->counter_enter++; +#endif vm_exec_loop() { opcase(LDNIL): { var_setnil(RA()); @@ -786,6 +817,9 @@ newframe: /* a new call frame */ dispatch(); } opcase(GETMBR): { +#if BE_USE_PERF_COUNTERS + vm->counter_get++; +#endif bvalue a_temp; /* copy result to a temp variable because the stack may be relocated in virtual member calls */ // bvalue *a = RA(), *b = RKB(), *c = RKC(); bvalue *b = RKB(), *c = RKC(); @@ -806,6 +840,9 @@ newframe: /* a new call frame */ dispatch(); } opcase(GETMET): { +#if BE_USE_PERF_COUNTERS + vm->counter_get++; +#endif bvalue a_temp; /* copy result to a temp variable because the stack may be relocated in virtual member calls */ bvalue *b = RKB(), *c = RKC(); if (var_isinstance(b) && var_isstr(c)) { @@ -837,6 +874,9 @@ newframe: /* a new call frame */ dispatch(); } opcase(SETMBR): { +#if BE_USE_PERF_COUNTERS + vm->counter_set++; +#endif bvalue *a = RA(), *b = RKB(), *c = RKC(); if (var_isinstance(a) && var_isstr(b)) { binstance *obj = var_toobj(a); @@ -971,6 +1011,9 @@ newframe: /* a new call frame */ dispatch(); } opcase(RAISE): { +#if BE_USE_PERF_COUNTERS + vm->counter_exc++; +#endif if (IGET_RA(ins) < 2) { /* A==2 means no arguments are passed to RAISE, i.e. rethrow with current exception */ bvalue *top = vm->top; top[0] = *RKB(); /* push the exception value to top */ @@ -985,6 +1028,9 @@ newframe: /* a new call frame */ dispatch(); } opcase(EXBLK): { +#if BE_USE_PERF_COUNTERS + vm->counter_try++; +#endif if (!IGET_RA(ins)) { be_except_block_setup(vm); if (be_setjmp(vm->errjmp->b)) { @@ -998,6 +1044,9 @@ newframe: /* a new call frame */ dispatch(); } opcase(CALL): { +#if BE_USE_PERF_COUNTERS + vm->counter_call++; +#endif bvalue *var = RA(); /* `var` is the register for the call followed by arguments */ int mode = 0, argc = IGET_RKB(ins); /* B contains number of arguments pushed on stack */ recall: /* goto: instantiation class and call constructor */ diff --git a/lib/libesp32/Berry/src/be_vm.h b/lib/libesp32/Berry/src/be_vm.h index 627c8fcaf..5890ecd41 100644 --- a/lib/libesp32/Berry/src/be_vm.h +++ b/lib/libesp32/Berry/src/be_vm.h @@ -104,6 +104,15 @@ struct bvm { #if BE_USE_OBSERVABILITY_HOOK bobshook obshook; #endif +#if BE_USE_PERF_COUNTERS + uint32_t counter_ins; /* instructions counter */ + uint32_t counter_enter; /* counter for times the VM was entered */ + uint32_t counter_call; /* counter for calls, VM or native */ + uint32_t counter_get; /* counter for GETMBR or GETMET */ + uint32_t counter_set; /* counter for SETMBR */ + uint32_t counter_try; /* counter for `try` statement */ + uint32_t counter_exc; /* counter for raised exceptions */ +#endif #if BE_USE_DEBUG_HOOK bvalue hook; bbyte hookmask; diff --git a/lib/libesp32/Berry/src/berry.h b/lib/libesp32/Berry/src/berry.h index f26081bde..9692d049f 100644 --- a/lib/libesp32/Berry/src/berry.h +++ b/lib/libesp32/Berry/src/berry.h @@ -403,8 +403,9 @@ typedef void(*bntvhook)(bvm *vm, bhookinfo *info); typedef void(*bobshook)(bvm *vm, int event, ...); enum beobshookevents { - BE_OBS_GC_START, // start of GC, arg = allocated size - BE_OBS_GC_END, // end of GC, arg = allocated size + BE_OBS_GC_START, /* start of GC, arg = allocated size */ + BE_OBS_GC_END, /* end of GC, arg = allocated size */ + BE_OBS_VM_HEARTBEAT, /* VM heartbeat called every million instructions */ }; /* FFI functions */ diff --git a/tasmota/my_user_config.h b/tasmota/my_user_config.h index 967560e03..824ae114a 100644 --- a/tasmota/my_user_config.h +++ b/tasmota/my_user_config.h @@ -990,6 +990,7 @@ //#define USE_WEBCAM // Add support for webcam #define USE_BERRY // Enable Berry scripting language + #define USE_BERRY_TIMEOUT 4000 // Timeout in ms, will raise an exception if running time exceeds this timeout #define USE_BERRY_PSRAM // Allocate Berry memory in PSRAM if PSRAM is connected - this might be slightly slower but leaves main memory intact // #define USE_BERRY_DEBUG // Compile Berry bytecode with line number information, makes exceptions easier to debug. Adds +8% of memory consumption for compiled code #define USE_WEBCLIENT // Enable `webclient` to make HTTP/HTTPS requests. Can be disabled for security reasons. diff --git a/tasmota/xdrv_52_0_berry_struct.ino b/tasmota/xdrv_52_0_berry_struct.ino index 33e048337..74ae1eee7 100644 --- a/tasmota/xdrv_52_0_berry_struct.ino +++ b/tasmota/xdrv_52_0_berry_struct.ino @@ -51,6 +51,7 @@ public: class BerrySupport { public: bvm *vm = nullptr; // berry vm + int32_t timeout = 0; // Berry heartbeat timeout, preventing code to run for too long. `0` means not enabled bool rules_busy = false; // are we already processing rules, avoid infinite loop bool autoexec_done = false; // do we still need to load 'autoexec.be' bool repl_active = false; // is REPL running (activates log recording) diff --git a/tasmota/xdrv_52_2_berry_native.ino b/tasmota/xdrv_52_2_berry_native.ino index 6d8cf0f54..b909b6352 100644 --- a/tasmota/xdrv_52_2_berry_native.ino +++ b/tasmota/xdrv_52_2_berry_native.ino @@ -492,5 +492,26 @@ int32_t be_convert_single_elt(bvm *vm, int32_t idx, const char * arg_type = null return ret; } +/*********************************************************************************************\ + * Manage timeout for Berry code + * +\*********************************************************************************************/ +void BrTimeoutStart(void) { + berry.timeout = millis() + USE_BERRY_TIMEOUT; + if (0 == berry.timeout) { + berry.timeout = 1; // rare case when value accidentally computes to zero + } + +} + +void BrTimeoutYield(void) { + if (0 != berry.timeout) { + BrTimeoutStart(); + } +} + +void BrTimeoutReset(void) { + berry.timeout = 0; // remove timer +} #endif // USE_BERRY diff --git a/tasmota/xdrv_52_3_berry_tasmota.ino b/tasmota/xdrv_52_3_berry_tasmota.ino index 95ea33e11..f98a5820a 100644 --- a/tasmota/xdrv_52_3_berry_tasmota.ino +++ b/tasmota/xdrv_52_3_berry_tasmota.ino @@ -308,7 +308,7 @@ extern "C" { // ESP object int32_t l_yield(bvm *vm); int32_t l_yield(bvm *vm) { - optimistic_yield(10); + BrTimeoutYield(); // reset timeout be_return_nil(vm); } diff --git a/tasmota/xdrv_52_9_berry.ino b/tasmota/xdrv_52_9_berry.ino index 091a1d608..2eaf1be0b 100644 --- a/tasmota/xdrv_52_9_berry.ino +++ b/tasmota/xdrv_52_9_berry.ino @@ -214,6 +214,7 @@ int32_t callBerryEventDispatcher(const char *type, const char *cmd, int32_t idx, be_pushstring(vm, cmd != nullptr ? cmd : ""); be_pushint(vm, idx); be_pushstring(vm, payload != nullptr ? payload : "{}"); // empty json + BrTimeoutStart(); if (data_len > 0) { be_pushbytes(vm, payload, data_len); // if data_len is set, we also push raw bytes ret = be_pcall(vm, 6); // 6 arguments @@ -221,6 +222,7 @@ int32_t callBerryEventDispatcher(const char *type, const char *cmd, int32_t idx, } else { ret = be_pcall(vm, 5); // 5 arguments } + BrTimeoutReset(); if (ret != 0) { BerryDumpErrorAndClear(vm, false); // log in Tasmota console only return ret; @@ -266,7 +268,18 @@ void BerryObservability(bvm *vm, int event...) { } } break; - default: break; + case BE_OBS_VM_HEARTBEAT: + { + // AddLog(LOG_LEVEL_INFO, ">>>: Heartbeat now=%i timeout=%i", millis(), berry.timeout); + if (berry.timeout) { + if (TimeReached(berry.timeout)) { + be_raise(vm, "timeout_error", "Berry code running for too long"); + } + } + } + break; + default: + break; } va_end(param); } @@ -348,10 +361,12 @@ void BrLoad(const char * script_name) { if (!be_isnil(berry.vm, -1)) { be_pushstring(berry.vm, script_name); + BrTimeoutStart(); if (be_pcall(berry.vm, 1) != 0) { BerryDumpErrorAndClear(berry.vm, false); return; } + BrTimeoutReset(); bool loaded = be_tobool(berry.vm, -2); // did it succeed? be_pop(berry.vm, 2); if (loaded) { @@ -389,7 +404,9 @@ void CmndBrRun(void) { } if (0 != ret_code) break; + BrTimeoutStart(); ret_code = be_pcall(berry.vm, 0); // execute code + BrTimeoutReset(); } while (0); if (0 == ret_code) { @@ -437,7 +454,9 @@ void BrREPLRun(char * cmd) { // AddLog(LOG_LEVEL_INFO, PSTR(">>>> be_loadbuffer cmd1 '%s', ret=%i"), cmd, ret_code); } if (0 == ret_code) { // code is ready to run + BrTimeoutStart(); ret_code = be_pcall(berry.vm, 0); // execute code + BrTimeoutReset(); // AddLog(LOG_LEVEL_INFO, PSTR(">>>> be_pcall ret=%i"), ret_code); if (0 == ret_code) { if (!be_isnil(berry.vm, 1)) {