From e46d07acb424d011b8fed2575447d4d91e01368b Mon Sep 17 00:00:00 2001 From: Stephan Hadinger Date: Fri, 26 Aug 2022 19:23:21 +0200 Subject: [PATCH] Berry add more metrics to GC --- lib/libesp32/berry/src/be_gc.c | 55 +++++++++++++++---- lib/libesp32/berry/src/be_vm.c | 5 ++ lib/libesp32/berry/src/be_vm.h | 19 +++++++ lib/libesp32/berry/src/berry.h | 2 + .../tasmota_xdrv_driver/xdrv_52_9_berry.ino | 25 +++++++++ 5 files changed, 96 insertions(+), 10 deletions(-) diff --git a/lib/libesp32/berry/src/be_gc.c b/lib/libesp32/berry/src/be_gc.c index 0254c8a19..f7532e239 100644 --- a/lib/libesp32/berry/src/be_gc.c +++ b/lib/libesp32/berry/src/be_gc.c @@ -135,22 +135,44 @@ bbool be_gc_fix_set(bvm *vm, bgcobject *obj, bbool fix) return was_fixed; } + +#if BE_USE_PERF_COUNTERS +#define GC_MARK(type) do { vm->gc_mark_##type++; } while (0); +#else +#define GC_MARK(type) do { } while (0); +#endif + +static void mark_gray_reset_counters(bvm *vm) { +#if BE_USE_PERF_COUNTERS + vm->gc_mark_string = 0; + vm->gc_mark_class = 0; + vm->gc_mark_proto = 0; + vm->gc_mark_instance = 0; + vm->gc_mark_map = 0; + vm->gc_mark_list = 0; + vm->gc_mark_closure = 0; + vm->gc_mark_ntvclos = 0; + vm->gc_mark_module = 0; + vm->gc_mark_comobj = 0; +#endif +} + static void mark_gray(bvm *vm, bgcobject *obj) { if (obj && gc_iswhite(obj) && !gc_isconst(obj)) { gc_setgray(obj); be_assert(!var_isstatic(obj)); switch (var_primetype(obj)) { - case BE_STRING: gc_setdark(obj); break; /* just set dark */ - case BE_CLASS: link_gray(vm, cast_class(obj)); break; - case BE_PROTO: link_gray(vm, cast_proto(obj)); break; - case BE_INSTANCE: link_gray(vm, cast_instance(obj)); break; - case BE_MAP: link_gray(vm, cast_map(obj)); break; - case BE_LIST: link_gray(vm, cast_list(obj)); break; - case BE_CLOSURE: link_gray(vm, cast_closure(obj)); break; - case BE_NTVCLOS: link_gray(vm, cast_ntvclos(obj)); break; - case BE_MODULE: link_gray(vm, cast_module(obj)); break; - case BE_COMOBJ: gc_setdark(obj); break; /* just set dark */ + case BE_STRING: gc_setdark(obj); GC_MARK(string); break; /* just set dark */ + case BE_CLASS: link_gray(vm, cast_class(obj)); GC_MARK(class); break; + case BE_PROTO: link_gray(vm, cast_proto(obj)); GC_MARK(proto); break; + case BE_INSTANCE: link_gray(vm, cast_instance(obj)); GC_MARK(instance); break; + case BE_MAP: link_gray(vm, cast_map(obj)); GC_MARK(map); break; + case BE_LIST: link_gray(vm, cast_list(obj)); GC_MARK(list); break; + case BE_CLOSURE: link_gray(vm, cast_closure(obj)); GC_MARK(closure); break; + case BE_NTVCLOS: link_gray(vm, cast_ntvclos(obj)); GC_MARK(ntvclos); break; + case BE_MODULE: link_gray(vm, cast_module(obj)); GC_MARK(module); break; + case BE_COMOBJ: gc_setdark(obj); GC_MARK(comobj); break; /* just set dark */ default: break; } } @@ -537,6 +559,12 @@ size_t be_gc_memcount(bvm *vm) return vm->gc.usage; } +#if BE_USE_PERF_COUNTERS +#define GC_TIMER(i) if (vm->microsfnct) { vm->micros_gc##i = vm->microsfnct(); } +#else +#define GC_TIMER(i) +#endif + void be_gc_collect(bvm *vm) { if (vm->gc.status & GC_HALT) { @@ -549,23 +577,30 @@ void be_gc_collect(bvm *vm) vm->counter_gc_freed = 0; #endif if (vm->obshook != NULL) (*vm->obshook)(vm, BE_OBS_GC_START, vm->gc.usage); + GC_TIMER(0); /* step 1: set root-set reference objects to unscanned */ + mark_gray_reset_counters(vm); /* reset all internal counters */ premark_internal(vm); /* object internal the VM */ premark_global(vm); /* global objects */ premark_stack(vm); /* stack objects */ premark_tracestack(vm); /* trace stack objects */ premark_fixed(vm); /* fixed objects */ + GC_TIMER(1); /* step 2: set unscanned objects to black */ mark_unscanned(vm); + GC_TIMER(2); /* step 3: destruct and delete unreachable objects */ destruct_white(vm); delete_white(vm); be_gcstrtab(vm); + GC_TIMER(3); /* step 4: reset the fixed objects */ reset_fixedlist(vm); + GC_TIMER(4); /* step 5: calculate the next GC threshold */ vm->gc.threshold = next_threshold(vm->gc); be_gc_memory_pools(vm); /* free unsued memory pools */ + GC_TIMER(5); #if BE_USE_PERF_COUNTERS size_t slors_used_after_gc, slots_allocated_after_gc; be_gc_memory_pools_info(vm, &slors_used_after_gc, &slots_allocated_after_gc); diff --git a/lib/libesp32/berry/src/be_vm.c b/lib/libesp32/berry/src/be_vm.c index 4555fc9b1..de738fb4d 100644 --- a/lib/libesp32/berry/src/be_vm.c +++ b/lib/libesp32/berry/src/be_vm.c @@ -1323,6 +1323,11 @@ BERRY_API void be_set_obs_hook(bvm *vm, bobshook hook) vm->obshook = hook; } +BERRY_API void be_set_obs_micros(bvm *vm, bmicrosfnct micros) +{ + vm->microsfnct = micros; +} + BERRY_API void be_set_ctype_func_hanlder(bvm *vm, bctypefunc handler) { vm->ctypefunc = handler; diff --git a/lib/libesp32/berry/src/be_vm.h b/lib/libesp32/berry/src/be_vm.h index 26d9f8b13..816d10cd1 100644 --- a/lib/libesp32/berry/src/be_vm.h +++ b/lib/libesp32/berry/src/be_vm.h @@ -106,6 +106,7 @@ struct bvm { bctypefunc ctypefunc; /* handler to ctype_func */ bbyte compopt; /* compilation options */ bobshook obshook; + bmicrosfnct microsfnct; /* fucntion to get time as a microsecond resolution */ #if BE_USE_PERF_COUNTERS uint32_t counter_ins; /* instructions counter */ uint32_t counter_enter; /* counter for times the VM was entered */ @@ -116,6 +117,24 @@ struct bvm { uint32_t counter_exc; /* counter for raised exceptions */ uint32_t counter_gc_kept; /* counter for objects scanned by last gc */ uint32_t counter_gc_freed; /* counter for objects freed by last gc */ + + uint32_t micros_gc0; + uint32_t micros_gc1; + uint32_t micros_gc2; + uint32_t micros_gc3; + uint32_t micros_gc4; + uint32_t micros_gc5; + + uint32_t gc_mark_string; + uint32_t gc_mark_class; + uint32_t gc_mark_proto; + uint32_t gc_mark_instance; + uint32_t gc_mark_map; + uint32_t gc_mark_list; + uint32_t gc_mark_closure; + uint32_t gc_mark_ntvclos; + uint32_t gc_mark_module; + uint32_t gc_mark_comobj; #endif #if BE_USE_DEBUG_HOOK bvalue hook; diff --git a/lib/libesp32/berry/src/berry.h b/lib/libesp32/berry/src/berry.h index e1eb2a777..e69df112a 100644 --- a/lib/libesp32/berry/src/berry.h +++ b/lib/libesp32/berry/src/berry.h @@ -411,6 +411,7 @@ typedef void(*bntvhook)(bvm *vm, bhookinfo *info); /* Observability hook */ typedef void(*bobshook)(bvm *vm, int event, ...); +typedef uint32_t(*bmicrosfnct)(void); enum beobshookevents { BE_OBS_PCALL_ERROR, /* called when be_callp() returned an error, most likely an exception */ BE_OBS_GC_START, /* start of GC, arg = allocated size */ @@ -562,6 +563,7 @@ BERRY_API void be_vm_delete(bvm *vm); /* Observability hook */ BERRY_API void be_set_obs_hook(bvm *vm, bobshook hook); +BERRY_API void be_set_obs_micros(bvm *vm, bmicrosfnct micros); BERRY_API void be_set_ctype_func_hanlder(bvm *vm, bctypefunc handler); BERRY_API bctypefunc be_get_ctype_func_hanlder(bvm *vm); diff --git a/tasmota/tasmota_xdrv_driver/xdrv_52_9_berry.ino b/tasmota/tasmota_xdrv_driver/xdrv_52_9_berry.ino index e4c302bdb..51d18abad 100644 --- a/tasmota/tasmota_xdrv_driver/xdrv_52_9_berry.ino +++ b/tasmota/tasmota_xdrv_driver/xdrv_52_9_berry.ino @@ -230,6 +230,30 @@ void BerryObservability(bvm *vm, int event...) { vm_usage, vm_usage2, vm_freed, vm_scanned, gc_elapsed, slots_used_before_gc, slots_allocated_before_gc, slots_used_after_gc, slots_allocated_after_gc); + + // Add more in-deptch metrics + AddLog(LOG_LEVEL_DEBUG_MORE, D_LOG_BERRY "GC timing (us) 1:%i 2:%i 3:%i 4:%i 5:%i total:%i", + vm->micros_gc1 - vm->micros_gc0, + vm->micros_gc2 - vm->micros_gc1, + vm->micros_gc3 - vm->micros_gc2, + vm->micros_gc4 - vm->micros_gc3, + vm->micros_gc5 - vm->micros_gc4, + vm->micros_gc5 - vm->micros_gc0 + ); + AddLog(LOG_LEVEL_DEBUG_MORE, D_LOG_BERRY "GC by type " + "string:%i class:%i proto:%i instance:%i map:%i " + "list:%i closure:%i ntvclos:%i module:%i comobj:%i", + vm->gc_mark_string, + vm->gc_mark_class, + vm->gc_mark_proto, + vm->gc_mark_instance, + vm->gc_mark_map, + vm->gc_mark_list, + vm->gc_mark_closure, + vm->gc_mark_ntvclos, + vm->gc_mark_module, + vm->gc_mark_comobj + ); // make new threshold tighter when we reach high memory usage if (!UsePSRAM() && vm->gc.threshold > 20*1024) { vm->gc.threshold = vm->gc.usage + 10*1024; // increase by only 10 KB @@ -287,6 +311,7 @@ void BerryInit(void) { do { berry.vm = be_vm_new(); /* create a virtual machine instance */ be_set_obs_hook(berry.vm, &BerryObservability); /* attach observability hook */ + be_set_obs_micros(berry.vm, (bmicrosfnct)µs); comp_set_named_gbl(berry.vm); /* Enable named globals in Berry compiler */ comp_set_strict(berry.vm); /* Enable strict mode in Berry compiler, equivalent of `import strict` */ be_set_ctype_func_hanlder(berry.vm, be_call_ctype_func);