From 2333a6a262ed147cca35be7187032db87d225390 Mon Sep 17 00:00:00 2001 From: Roman Zeyde Date: Sun, 16 Mar 2025 08:49:29 +0200 Subject: [PATCH 1/2] feat(core): log GC info in case of OOM Enabled on debug firmware and non-frozen emulator. [no changelog] --- core/SConscript.firmware | 10 +++++- core/SConscript.unix | 6 ++-- .../upymod/modtrezorutils/modtrezorutils.c | 36 +++++++++++++++++-- core/mocks/generated/trezorutils.pyi | 5 +++ core/src/trezor/utils.py | 7 ++++ vendor/micropython | 2 +- 6 files changed, 58 insertions(+), 8 deletions(-) diff --git a/core/SConscript.firmware b/core/SConscript.firmware index 583143cae7f..fa924c877a3 100644 --- a/core/SConscript.firmware +++ b/core/SConscript.firmware @@ -395,9 +395,17 @@ ui.init_ui(TREZOR_MODEL, "firmware", RUST_UI_FEATURES) SOURCE_QSTR = SOURCE_MOD + SOURCE_MICROPYTHON + SOURCE_MICROPYTHON_SPEED +if PYOPT == '0': + DEBUG_FLAGS = "-DMICROPY_OOM_CALLBACK=1" +else: + DEBUG_FLAGS = "-DMICROPY_OOM_CALLBACK=0" + env = Environment( ENV=os.environ, - CFLAGS=f"{ARGUMENTS.get('CFLAGS', '')} -DPRODUCTION={int(PRODUCTION)} -DPYOPT={PYOPT} -DBOOTLOADER_QA={int(BOOTLOADER_QA)} -DBITCOIN_ONLY={BITCOIN_ONLY}", + CFLAGS=( + f"{ARGUMENTS.get('CFLAGS', '')} -DPRODUCTION={int(PRODUCTION)} -DPYOPT={PYOPT} " + f"-DBOOTLOADER_QA={int(BOOTLOADER_QA)} -DBITCOIN_ONLY={BITCOIN_ONLY} {DEBUG_FLAGS}" + ), CPPDEFINES_IMPLICIT=[], CPPDEFPREFIX="-D'", CPPDEFSUFFIX="'", diff --git a/core/SConscript.unix b/core/SConscript.unix index 17c5a1effc5..52e1b52a95f 100644 --- a/core/SConscript.unix +++ b/core/SConscript.unix @@ -422,13 +422,13 @@ ui.init_ui(TREZOR_MODEL, "firmware", RUST_UI_FEATURES) SOURCE_QSTR = SOURCE_MOD + SOURCE_MICROPYTHON + SOURCE_UNIX if PYOPT == '0' or not FROZEN: - STATIC="-DSTATIC=" + DEBUG_FLAGS = "-DMICROPY_OOM_CALLBACK=1 -DSTATIC=" else: - STATIC="" + DEBUG_FLAGS = "-DMICROPY_OOM_CALLBACK=0" env = Environment( ENV=os.environ, - CFLAGS=ARGUMENTS.get("CFLAGS", "") + f" -DCONFIDENTIAL= -DPYOPT={PYOPT} -DBITCOIN_ONLY={BITCOIN_ONLY} {STATIC}", + CFLAGS=ARGUMENTS.get("CFLAGS", "") + f" -DCONFIDENTIAL= -DPYOPT={PYOPT} -DBITCOIN_ONLY={BITCOIN_ONLY} {DEBUG_FLAGS}", CPPDEFPREFIX="-D'", CPPDEFSUFFIX="'", ) diff --git a/core/embed/upymod/modtrezorutils/modtrezorutils.c b/core/embed/upymod/modtrezorutils/modtrezorutils.c index 73038b56af2..f34ce4df411 100644 --- a/core/embed/upymod/modtrezorutils/modtrezorutils.c +++ b/core/embed/upymod/modtrezorutils/modtrezorutils.c @@ -20,6 +20,9 @@ #include #include +#if MICROPY_OOM_CALLBACK +#include +#endif #include "py/objstr.h" #include "py/runtime.h" @@ -243,7 +246,8 @@ STATIC mp_obj_t mod_trezorutils_sd_hotswap_enabled(void) { STATIC MP_DEFINE_CONST_FUN_OBJ_0(mod_trezorutils_sd_hotswap_enabled_obj, mod_trezorutils_sd_hotswap_enabled); -#if !PYOPT && LOG_STACK_USAGE +#if !PYOPT +#if LOG_STACK_USAGE /// def zero_unused_stack() -> None: /// """ /// Zero unused stack memory. @@ -275,7 +279,27 @@ STATIC mp_obj_t mod_trezorutils_estimate_unused_stack(void) { STATIC MP_DEFINE_CONST_FUN_OBJ_0(mod_trezorutils_estimate_unused_stack_obj, mod_trezorutils_estimate_unused_stack); -#endif // !PYOPT && LOG_STACK_USAGE +#endif // LOG_STACK_USAGE + +#if MICROPY_OOM_CALLBACK +static void gc_oom_callback(void) { + gc_dump_info(); +} + +/// if __debug__: +/// def enable_oom_dump() -> None: +/// """ +/// Dump GC info in case of an OOM. +/// """ +STATIC mp_obj_t mod_trezorutils_enable_oom_dump(void) { + gc_set_oom_callback(gc_oom_callback); + return mp_const_none; +} +STATIC MP_DEFINE_CONST_FUN_OBJ_0(mod_trezorutils_enable_oom_dump_obj, + mod_trezorutils_enable_oom_dump); +#endif // MICROPY_OOM_CALLBACK + +#endif // !PYOPT /// def reboot_to_bootloader( /// boot_command : int = 0, @@ -482,11 +506,17 @@ STATIC const mp_rom_map_elem_t mp_module_trezorutils_globals_table[] = { MP_ROM_PTR(&mod_trezorutils_unit_packaging_obj)}, {MP_ROM_QSTR(MP_QSTR_unit_btconly), MP_ROM_PTR(&mod_trezorutils_unit_btconly_obj)}, -#if !PYOPT && LOG_STACK_USAGE +#if !PYOPT +#if LOG_STACK_USAGE {MP_ROM_QSTR(MP_QSTR_zero_unused_stack), MP_ROM_PTR(&mod_trezorutils_zero_unused_stack_obj)}, {MP_ROM_QSTR(MP_QSTR_estimate_unused_stack), MP_ROM_PTR(&mod_trezorutils_estimate_unused_stack_obj)}, +#endif +#if MICROPY_OOM_CALLBACK + {MP_ROM_QSTR(MP_QSTR_enable_oom_dump), + MP_ROM_PTR(&mod_trezorutils_enable_oom_dump_obj)}, +#endif #endif {MP_ROM_QSTR(MP_QSTR_sd_hotswap_enabled), MP_ROM_PTR(&mod_trezorutils_sd_hotswap_enabled_obj)}, diff --git a/core/mocks/generated/trezorutils.pyi b/core/mocks/generated/trezorutils.pyi index 65185bcd501..35c463cdb92 100644 --- a/core/mocks/generated/trezorutils.pyi +++ b/core/mocks/generated/trezorutils.pyi @@ -100,6 +100,11 @@ def estimate_unused_stack() -> int: """ Estimate unused stack size. """ +if __debug__: + def enable_oom_dump() -> None: + """ + Dump GC info in case of an OOM. + """ # upymod/modtrezorutils/modtrezorutils.c diff --git a/core/src/trezor/utils.py b/core/src/trezor/utils.py index afe88773d0c..ebb00575609 100644 --- a/core/src/trezor/utils.py +++ b/core/src/trezor/utils.py @@ -125,6 +125,13 @@ def presize_module(modname: str, size: int) -> None: if __debug__: from ubinascii import hexlify + try: + from trezorutils import enable_oom_dump + + enable_oom_dump() + except ImportError: + pass + def mem_dump(filename: str) -> None: from micropython import mem_info diff --git a/vendor/micropython b/vendor/micropython index d2d97062f7e..e4d81eb3802 160000 --- a/vendor/micropython +++ b/vendor/micropython @@ -1 +1 @@ -Subproject commit d2d97062f7ef731109e895760035b4e3e047ad8c +Subproject commit e4d81eb3802b567960ae9405b33c0c9e6efe7f0d From 5fd168c363db860b61a251c045d6cc487f5e5545 Mon Sep 17 00:00:00 2001 From: Roman Zeyde Date: Sun, 16 Mar 2025 12:48:46 +0200 Subject: [PATCH 2/2] feat(core): dump GC arena on OOM Enabled for debug firmware and non-frozen emulator. JSON dump can be extracted from debug log and analyzed using: $ awk '/^\[$/,/^\]$/' dump.json $ core/tools/analyze-memory-dump.py dump.json [no changelog] --- core/SConscript.firmware | 2 +- core/embed/rust/librust.h | 4 +- .../modtrezorutils/modtrezorutils-meminfo.h | 92 ++++++++++++++----- .../upymod/modtrezorutils/modtrezorutils.c | 3 + core/mocks/generated/trezorutils.pyi | 3 +- core/tools/analyze-memory-dump.py | 25 ++--- 6 files changed, 88 insertions(+), 41 deletions(-) diff --git a/core/SConscript.firmware b/core/SConscript.firmware index fa924c877a3..8aa9149977e 100644 --- a/core/SConscript.firmware +++ b/core/SConscript.firmware @@ -396,7 +396,7 @@ ui.init_ui(TREZOR_MODEL, "firmware", RUST_UI_FEATURES) SOURCE_QSTR = SOURCE_MOD + SOURCE_MICROPYTHON + SOURCE_MICROPYTHON_SPEED if PYOPT == '0': - DEBUG_FLAGS = "-DMICROPY_OOM_CALLBACK=1" + DEBUG_FLAGS = "-DMICROPY_OOM_CALLBACK=1 -DSTATIC=" else: DEBUG_FLAGS = "-DMICROPY_OOM_CALLBACK=0" diff --git a/core/embed/rust/librust.h b/core/embed/rust/librust.h index 2ad5eb0db9d..83c222b6502 100644 --- a/core/embed/rust/librust.h +++ b/core/embed/rust/librust.h @@ -2,7 +2,7 @@ #include "librust_qstr.h" -#ifdef TREZOR_EMULATOR +#if !PYOPT mp_obj_t protobuf_debug_msg_type(); mp_obj_t protobuf_debug_msg_def_type(); #endif @@ -11,6 +11,6 @@ extern mp_obj_module_t mp_module_trezorproto; extern mp_obj_module_t mp_module_trezorui_api; extern mp_obj_module_t mp_module_trezortranslate; -#ifdef TREZOR_EMULATOR +#if !PYOPT mp_obj_t ui_debug_layout_type(); #endif diff --git a/core/embed/upymod/modtrezorutils/modtrezorutils-meminfo.h b/core/embed/upymod/modtrezorutils/modtrezorutils-meminfo.h index 79b940a2ad9..576c04bb98a 100644 --- a/core/embed/upymod/modtrezorutils/modtrezorutils-meminfo.h +++ b/core/embed/upymod/modtrezorutils/modtrezorutils-meminfo.h @@ -17,7 +17,7 @@ * along with this program. If not, see . */ -#if !TREZOR_EMULATOR || PYOPT +#if PYOPT #define MEMINFO_DICT_ENTRIES /* empty */ #else @@ -38,6 +38,14 @@ #include "embed/rust/librust.h" #include "embed/upymod/trezorobj.h" +#if !TREZOR_EMULATOR +#define fopen(path, mode) &mp_plat_print +#define fprintf mp_printf +#define fflush(f) +#define fclose(f) +#define FILE const mp_print_t +#endif + #define WORDS_PER_BLOCK ((MICROPY_BYTES_PER_GC_BLOCK) / MP_BYTES_PER_OBJ_WORD) #define BYTES_PER_BLOCK (MICROPY_BYTES_PER_GC_BLOCK) @@ -149,9 +157,29 @@ bool is_short(mp_const_obj_t value) { mp_obj_is_small_int(value) || !VERIFY_PTR(value); } +static void escape_and_dump_string(FILE *out, const char *unescaped) { + fprintf(out, "\""); + for (; *unescaped; ++unescaped) { + char c = *unescaped; + if (c == '\n') { + fprintf(out, "\\n"); + } else if (c == '\r') { + fprintf(out, "\\r"); + } else if (c == '\"') { + fprintf(out, "\\\""); + } else if (c == '\\') { + fprintf(out, "\\\\"); + } else if (c >= 0x20 && c < 0x7F) { + fprintf(out, "%c", c); + } else { + fprintf(out, "\\u%04x", c); + } + } + fprintf(out, "\""); +} + static void print_type(FILE *out, const char *typename, const char *shortval, const void *ptr, bool end) { - static char unescaped[1000]; size_t size = 0; if (!is_short(ptr)) { size = find_allocated_size(ptr); @@ -159,14 +187,8 @@ static void print_type(FILE *out, const char *typename, const char *shortval, fprintf(out, "{\"type\": \"%s\", \"alloc\": %ld, \"ptr\": \"%p\"", typename, size, ptr); if (shortval) { - assert(strlen(shortval) < 1000); - char *c = unescaped; - while (*shortval) { - if (*shortval == '\\' || *shortval == '"') *c++ = '\\'; - *c++ = *shortval++; - } - *c = 0; - fprintf(out, ", \"shortval\": \"%s\"", unescaped); + fprintf(out, ", \"shortval\": "); + escape_and_dump_string(out, shortval); } else { fprintf(out, ", \"shortval\": null"); } @@ -199,7 +221,7 @@ void dump_short(FILE *out, mp_const_obj_t value) { } else if (mp_obj_is_small_int(value)) { static char num_buf[100]; - snprintf(num_buf, 100, "%ld", MP_OBJ_SMALL_INT_VALUE(value)); + snprintf(num_buf, 100, INT_FMT, MP_OBJ_SMALL_INT_VALUE(value)); print_type(out, "smallint", num_buf, NULL, true); } else if (!VERIFY_PTR(value)) { @@ -680,10 +702,11 @@ void dump_qstr_pool(FILE *out, const qstr_pool_t *pool) { for (const char *const *q = pool->qstrs, *const *q_top = pool->qstrs + pool->len; q < q_top; q++) { + escape_and_dump_string(out, Q_GET_DATA(*q)); if (q < (q_top - 1)) - fprintf(out, "\"%s\",\n", Q_GET_DATA(*q)); + fprintf(out, ",\n"); else - fprintf(out, "\"%s\"]\n", Q_GET_DATA(*q)); + fprintf(out, "]\n"); } fprintf(out, "},\n"); for (const char *const *q = pool->qstrs, *const *q_top = @@ -709,15 +732,19 @@ void dump_qstrdata(FILE *out) { } } -/// def meminfo(filename: str) -> None: -/// """Dumps map of micropython GC arena to a file. -/// The JSON file can be decoded by analyze-memory-dump.py -/// Only available in the emulator. -/// """ -STATIC mp_obj_t mod_trezorutils_meminfo(mp_obj_t filename) { - size_t fn_len; - FILE *out = fopen(mp_obj_str_get_data(filename, &fn_len), "w"); - fprintf(out, "["); +static void dump_meminfo_json(FILE *out) { + bool should_close = true; + if (out == NULL) { + should_close = false; +#if TREZOR_EMULATOR + out = stdout; +#else + out = &mp_plat_print; +#endif + } + fprintf(out, "\n[\n[" UINT_FMT ", " UINT_FMT ", " UINT_FMT "],\n", + (mp_uint_t)MP_STATE_MEM(gc_pool_start), + (mp_uint_t)MP_STATE_MEM(gc_pool_end), BYTES_PER_BLOCK); // void **ptrs = (void **)(void *)&mp_state_ctx; // size_t root_start = offsetof(mp_state_ctx_t, thread.dict_locals); @@ -768,8 +795,12 @@ STATIC mp_obj_t mod_trezorutils_meminfo(mp_obj_t filename) { pool = pool->prev; } - fprintf(out, "null]\n"); - fclose(out); + fprintf(out, "null\n]\n"); + if (should_close) { + fclose(out); + } else { + fflush(out); + } for (size_t block = 0; block < MP_STATE_MEM(gc_alloc_table_byte_len) * BLOCKS_PER_ATB; block++) { @@ -779,6 +810,19 @@ STATIC mp_obj_t mod_trezorutils_meminfo(mp_obj_t filename) { } gc_dump_alloc_table(); +} + +/// def meminfo(filename: str | None) -> None: +/// """Dumps map of micropython GC arena to a file. +/// The JSON file can be decoded by analyze-memory-dump.py +/// """ +STATIC mp_obj_t mod_trezorutils_meminfo(mp_obj_t filename) { + size_t fn_len; + FILE *out = (filename == mp_const_none) + ? NULL + : fopen(mp_obj_str_get_data(filename, &fn_len), "w"); + (void)fn_len; + dump_meminfo_json(out); return mp_const_none; } STATIC MP_DEFINE_CONST_FUN_OBJ_1(mod_trezorutils_meminfo_obj, diff --git a/core/embed/upymod/modtrezorutils/modtrezorutils.c b/core/embed/upymod/modtrezorutils/modtrezorutils.c index f34ce4df411..283f8250bf3 100644 --- a/core/embed/upymod/modtrezorutils/modtrezorutils.c +++ b/core/embed/upymod/modtrezorutils/modtrezorutils.c @@ -284,6 +284,9 @@ STATIC MP_DEFINE_CONST_FUN_OBJ_0(mod_trezorutils_estimate_unused_stack_obj, #if MICROPY_OOM_CALLBACK static void gc_oom_callback(void) { gc_dump_info(); +#if BLOCK_ON_VCP || TREZOR_EMULATOR + dump_meminfo_json(NULL); // dump to stdout +#endif } /// if __debug__: diff --git a/core/mocks/generated/trezorutils.pyi b/core/mocks/generated/trezorutils.pyi index 35c463cdb92..2ec1af7e11c 100644 --- a/core/mocks/generated/trezorutils.pyi +++ b/core/mocks/generated/trezorutils.pyi @@ -2,10 +2,9 @@ from typing import * # upymod/modtrezorutils/modtrezorutils-meminfo.h -def meminfo(filename: str) -> None: +def meminfo(filename: str | None) -> None: """Dumps map of micropython GC arena to a file. The JSON file can be decoded by analyze-memory-dump.py - Only available in the emulator. """ diff --git a/core/tools/analyze-memory-dump.py b/core/tools/analyze-memory-dump.py index c12b0b8d314..fec52018663 100755 --- a/core/tools/analyze-memory-dump.py +++ b/core/tools/analyze-memory-dump.py @@ -30,7 +30,8 @@ with open(sys.argv[1]) as f: - MEMMAP = json.load(f) + MEMMAP = iter(json.load(f)) + (min_ptr, max_ptr, bytes_per_block) = next(MEMMAP) # filter out notices and comments @@ -57,7 +58,13 @@ def ptr_or_shortval(maybe_ptr): def is_ignored_ptr(ptr): - return (ptr == "(nil)" or ptr.startswith("0x5") or ptr.startswith("0x6")) + if ptr == "(nil)": + return True + + if isinstance(ptr, str): + ptr = int(ptr, 16) + + return not (min_ptr <= ptr < max_ptr) def deref_or_shortval(maybe_ptr): @@ -155,13 +162,6 @@ def ptrval(self): allobjs = list(MEMORY.values()) allobjs.sort(key=lambda x: x.ptr) -min_ptr = min( - item.ptrval() - for item in allobjs - if not is_ignored_ptr(item.ptr) -) -max_ptr = max(item.ptrval() for item in allobjs if item.ptr != "(nil)") - types = { "anystr": "S", @@ -201,9 +201,10 @@ def ptrval(self): pixels_per_line = len( "................................................................" ) -pixelsize = 0x800 // pixels_per_line -maxline = ((max_ptr - min_ptr) & ~0x7FF) + (0x800 * 2) -pixelmap = [None] * (maxline // pixelsize) +pixelsize = bytes_per_block +bytes_per_line = bytes_per_block * pixels_per_line +maxline = ((max_ptr - min_ptr) & ~(bytes_per_line - 1)) + (bytes_per_line * 2) +pixelmap = [None] * 2*(maxline // pixelsize) def pixel_index(ptrval):