use log for memory comsumption

This commit is contained in:
TianlongLiang 2026-03-31 15:41:21 +08:00
parent 1446918882
commit 81183b3509
10 changed files with 48 additions and 87 deletions

View File

@ -103,10 +103,6 @@ if GetDepend(['WAMR_BUILD_MEMORY_PROFILING']):
CPPDEFINES += ['WASM_ENABLE_MEMORY_PROFILING=1'] CPPDEFINES += ['WASM_ENABLE_MEMORY_PROFILING=1']
print('[WAMR] Memory profiling enabled') print('[WAMR] Memory profiling enabled')
if GetDepend(['WAMR_BUILD_MEM_PROFILING_USE_LOG']):
CPPDEFINES += ['WASM_MEM_PROFILING_USE_LOG=1']
print('[WAMR] Memory profiling uses structured logging')
if GetDepend(['WAMR_BUILD_MEMORY_TRACING']): if GetDepend(['WAMR_BUILD_MEMORY_TRACING']):
CPPDEFINES += ['WASM_ENABLE_MEMORY_TRACING=1'] CPPDEFINES += ['WASM_ENABLE_MEMORY_TRACING=1']
print('[WAMR] Memory tracing enabled') print('[WAMR] Memory tracing enabled')

View File

@ -478,10 +478,6 @@ if (WAMR_BUILD_MEMORY_PROFILING EQUAL 1)
add_definitions (-DWASM_ENABLE_MEMORY_PROFILING=1) add_definitions (-DWASM_ENABLE_MEMORY_PROFILING=1)
message (" Memory profiling enabled") message (" Memory profiling enabled")
endif () endif ()
if (WAMR_BUILD_MEM_PROFILING_USE_LOG EQUAL 1)
add_definitions (-DWASM_MEM_PROFILING_USE_LOG=1)
message (" Memory profiling uses structured logging")
endif ()
if (WAMR_BUILD_MEMORY_TRACING EQUAL 1) if (WAMR_BUILD_MEMORY_TRACING EQUAL 1)
add_definitions (-DWASM_ENABLE_MEMORY_TRACING=1) add_definitions (-DWASM_ENABLE_MEMORY_TRACING=1)
message (" Memory tracing enabled") message (" Memory tracing enabled")

View File

@ -56,10 +56,6 @@ if (NOT CMAKE_BUILD_EARLY_EXPANSION)
set (WAMR_BUILD_MEMORY_PROFILING 1) set (WAMR_BUILD_MEMORY_PROFILING 1)
endif () endif ()
if (CONFIG_WAMR_ENABLE_MEM_PROFILING_USE_LOG)
set (WAMR_BUILD_MEM_PROFILING_USE_LOG 1)
endif ()
if (CONFIG_WAMR_ENABLE_MEMORY_TRACING) if (CONFIG_WAMR_ENABLE_MEMORY_TRACING)
set (WAMR_BUILD_MEMORY_TRACING 1) set (WAMR_BUILD_MEMORY_TRACING 1)
endif () endif ()

View File

@ -347,13 +347,6 @@ unless used elsewhere */
#define WASM_ENABLE_MEMORY_TRACING 0 #define WASM_ENABLE_MEMORY_TRACING 0
#endif #endif
/* Use structured logging (LOG_VERBOSE) instead of os_printf for memory
profiling/tracing output. When enabled, output respects the log verbose
level set by bh_log_set_verbose_level(). */
#ifndef WASM_MEM_PROFILING_USE_LOG
#define WASM_MEM_PROFILING_USE_LOG 0
#endif
/* Performance profiling */ /* Performance profiling */
#ifndef WASM_ENABLE_PERF_PROFILING #ifndef WASM_ENABLE_PERF_PROFILING
#define WASM_ENABLE_PERF_PROFILING 0 #define WASM_ENABLE_PERF_PROFILING 0

View File

@ -268,7 +268,7 @@ register_natives(const char *module_name, NativeSymbol *native_symbols,
if (!(node = wasm_runtime_malloc(sizeof(NativeSymbolsNode)))) if (!(node = wasm_runtime_malloc(sizeof(NativeSymbolsNode))))
return false; return false;
#if WASM_ENABLE_MEMORY_TRACING != 0 #if WASM_ENABLE_MEMORY_TRACING != 0
MEM_PROF_PRINTF("Register native, size: %u\n", sizeof(NativeSymbolsNode)); LOG_VERBOSE("Register native, size: %u", sizeof(NativeSymbolsNode));
#endif #endif
node->module_name = module_name; node->module_name = module_name;

View File

@ -2029,26 +2029,26 @@ wasm_runtime_dump_module_mem_consumption(const WASMModuleCommon *module)
} }
#endif #endif
MEM_PROF_PRINTF("WASM module memory consumption, total size: %u\n", LOG_VERBOSE("WASM module memory consumption, total size: %u",
mem_conspn.total_size); mem_conspn.total_size);
MEM_PROF_PRINTF(" module struct size: %u\n", LOG_VERBOSE(" module struct size: %u",
mem_conspn.module_struct_size); mem_conspn.module_struct_size);
MEM_PROF_PRINTF(" types size: %u\n", mem_conspn.types_size); LOG_VERBOSE(" types size: %u", mem_conspn.types_size);
MEM_PROF_PRINTF(" imports size: %u\n", mem_conspn.imports_size); LOG_VERBOSE(" imports size: %u", mem_conspn.imports_size);
MEM_PROF_PRINTF(" funcs size: %u\n", mem_conspn.functions_size); LOG_VERBOSE(" funcs size: %u", mem_conspn.functions_size);
MEM_PROF_PRINTF(" tables size: %u\n", mem_conspn.tables_size); LOG_VERBOSE(" tables size: %u", mem_conspn.tables_size);
MEM_PROF_PRINTF(" memories size: %u\n", mem_conspn.memories_size); LOG_VERBOSE(" memories size: %u", mem_conspn.memories_size);
MEM_PROF_PRINTF(" globals size: %u\n", mem_conspn.globals_size); LOG_VERBOSE(" globals size: %u", mem_conspn.globals_size);
MEM_PROF_PRINTF(" exports size: %u\n", mem_conspn.exports_size); LOG_VERBOSE(" exports size: %u", mem_conspn.exports_size);
MEM_PROF_PRINTF(" table segs size: %u\n", mem_conspn.table_segs_size); LOG_VERBOSE(" table segs size: %u", mem_conspn.table_segs_size);
MEM_PROF_PRINTF(" data segs size: %u\n", mem_conspn.data_segs_size); LOG_VERBOSE(" data segs size: %u", mem_conspn.data_segs_size);
MEM_PROF_PRINTF(" const strings size: %u\n", mem_conspn.const_strs_size); LOG_VERBOSE(" const strings size: %u", mem_conspn.const_strs_size);
#if WASM_ENABLE_LOAD_CUSTOM_SECTION != 0 #if WASM_ENABLE_LOAD_CUSTOM_SECTION != 0
MEM_PROF_PRINTF(" custom sections size: %u\n", LOG_VERBOSE(" custom sections size: %u",
mem_conspn.custom_sections_size); mem_conspn.custom_sections_size);
#endif #endif
#if WASM_ENABLE_AOT != 0 #if WASM_ENABLE_AOT != 0
MEM_PROF_PRINTF(" aot code size: %u\n", mem_conspn.aot_code_size); LOG_VERBOSE(" aot code size: %u", mem_conspn.aot_code_size);
#endif #endif
} }
@ -2071,16 +2071,16 @@ wasm_runtime_dump_module_inst_mem_consumption(
} }
#endif #endif
MEM_PROF_PRINTF("WASM module inst memory consumption, total size: %lu\n", LOG_VERBOSE("WASM module inst memory consumption, total size: %lu",
mem_conspn.total_size); mem_conspn.total_size);
MEM_PROF_PRINTF(" module inst struct size: %u\n", LOG_VERBOSE(" module inst struct size: %u",
mem_conspn.module_inst_struct_size); mem_conspn.module_inst_struct_size);
MEM_PROF_PRINTF(" memories size: %lu\n", mem_conspn.memories_size); LOG_VERBOSE(" memories size: %lu", mem_conspn.memories_size);
MEM_PROF_PRINTF(" app heap size: %u\n", mem_conspn.app_heap_size); LOG_VERBOSE(" app heap size: %u", mem_conspn.app_heap_size);
MEM_PROF_PRINTF(" tables size: %u\n", mem_conspn.tables_size); LOG_VERBOSE(" tables size: %u", mem_conspn.tables_size);
MEM_PROF_PRINTF(" functions size: %u\n", mem_conspn.functions_size); LOG_VERBOSE(" functions size: %u", mem_conspn.functions_size);
MEM_PROF_PRINTF(" globals size: %u\n", mem_conspn.globals_size); LOG_VERBOSE(" globals size: %u", mem_conspn.globals_size);
MEM_PROF_PRINTF(" exports size: %u\n", mem_conspn.exports_size); LOG_VERBOSE(" exports size: %u", mem_conspn.exports_size);
} }
void void
@ -2089,15 +2089,15 @@ wasm_runtime_dump_exec_env_mem_consumption(const WASMExecEnv *exec_env)
uint32 total_size = uint32 total_size =
offsetof(WASMExecEnv, wasm_stack_u.bottom) + exec_env->wasm_stack_size; offsetof(WASMExecEnv, wasm_stack_u.bottom) + exec_env->wasm_stack_size;
MEM_PROF_PRINTF("Exec env memory consumption, total size: %u\n", LOG_VERBOSE("Exec env memory consumption, total size: %u",
total_size); total_size);
MEM_PROF_PRINTF(" exec env struct size: %u\n", LOG_VERBOSE(" exec env struct size: %u",
offsetof(WASMExecEnv, wasm_stack_u.bottom)); offsetof(WASMExecEnv, wasm_stack_u.bottom));
#if WASM_ENABLE_INTERP != 0 && WASM_ENABLE_FAST_INTERP == 0 #if WASM_ENABLE_INTERP != 0 && WASM_ENABLE_FAST_INTERP == 0
MEM_PROF_PRINTF(" block addr cache size: %u\n", LOG_VERBOSE(" block addr cache size: %u",
sizeof(exec_env->block_addr_cache)); sizeof(exec_env->block_addr_cache));
#endif #endif
MEM_PROF_PRINTF(" stack size: %u\n", exec_env->wasm_stack_size); LOG_VERBOSE(" stack size: %u", exec_env->wasm_stack_size);
} }
uint32 uint32
@ -2158,20 +2158,20 @@ wasm_runtime_dump_mem_consumption(WASMExecEnv *exec_env)
+ exec_env->wasm_stack_size + module_mem_consps.total_size + exec_env->wasm_stack_size + module_mem_consps.total_size
+ module_inst_mem_consps.total_size; + module_inst_mem_consps.total_size;
MEM_PROF_PRINTF("\nMemory consumption summary (bytes):\n"); LOG_VERBOSE("Memory consumption summary (bytes):");
wasm_runtime_dump_module_mem_consumption(module_common); wasm_runtime_dump_module_mem_consumption(module_common);
wasm_runtime_dump_module_inst_mem_consumption(module_inst_common); wasm_runtime_dump_module_inst_mem_consumption(module_inst_common);
wasm_runtime_dump_exec_env_mem_consumption(exec_env); wasm_runtime_dump_exec_env_mem_consumption(exec_env);
MEM_PROF_PRINTF("\nTotal memory consumption of module, module inst and " LOG_VERBOSE("Total memory consumption of module, module inst and "
"exec env: %" PRIu64 "\n", "exec env: %" PRIu64,
total_size); total_size);
MEM_PROF_PRINTF("Total interpreter stack used: %u\n", LOG_VERBOSE("Total interpreter stack used: %u",
exec_env->max_wasm_stack_used); exec_env->max_wasm_stack_used);
if (max_aux_stack_used != (uint32)-1) if (max_aux_stack_used != (uint32)-1)
MEM_PROF_PRINTF("Total auxiliary stack used: %u\n", max_aux_stack_used); LOG_VERBOSE("Total auxiliary stack used: %u", max_aux_stack_used);
else else
MEM_PROF_PRINTF("Total aux stack used: no enough info to profile\n"); LOG_VERBOSE("Total aux stack used: no enough info to profile");
/* /*
* Report the native stack usage estimation. * Report the native stack usage estimation.
@ -2183,13 +2183,13 @@ wasm_runtime_dump_mem_consumption(WASMExecEnv *exec_env)
* It doesn't cover host func implementations, signal handlers, etc. * It doesn't cover host func implementations, signal handlers, etc.
*/ */
if (exec_env->native_stack_top_min != (void *)UINTPTR_MAX) if (exec_env->native_stack_top_min != (void *)UINTPTR_MAX)
MEM_PROF_PRINTF("Native stack left: %zd\n", LOG_VERBOSE("Native stack left: %zd",
exec_env->native_stack_top_min exec_env->native_stack_top_min
- exec_env->native_stack_boundary); - exec_env->native_stack_boundary);
else else
MEM_PROF_PRINTF("Native stack left: no enough info to profile\n"); LOG_VERBOSE("Native stack left: no enough info to profile");
MEM_PROF_PRINTF("Total app heap used: %u\n", app_heap_peak_size); LOG_VERBOSE("Total app heap used: %u", app_heap_peak_size);
} }
#endif /* end of (WASM_ENABLE_MEMORY_PROFILING != 0) \ #endif /* end of (WASM_ENABLE_MEMORY_PROFILING != 0) \
|| (WASM_ENABLE_MEMORY_TRACING != 0) */ || (WASM_ENABLE_MEMORY_TRACING != 0) */

View File

@ -76,10 +76,10 @@ gc_init_with_pool(char *buf, gc_size_t buf_size)
heap_max_size = (uint32)(buf_end - base_addr) & (uint32)~7; heap_max_size = (uint32)(buf_end - base_addr) & (uint32)~7;
#if WASM_ENABLE_MEMORY_TRACING != 0 #if WASM_ENABLE_MEMORY_TRACING != 0
MEM_PROF_PRINTF("Heap created, total size: %u\n", buf_size); LOG_VERBOSE("Heap created, total size: %u", buf_size);
MEM_PROF_PRINTF(" heap struct size: %u\n", sizeof(gc_heap_t)); LOG_VERBOSE(" heap struct size: %u", sizeof(gc_heap_t));
MEM_PROF_PRINTF(" actual heap size: %u\n", heap_max_size); LOG_VERBOSE(" actual heap size: %u", heap_max_size);
MEM_PROF_PRINTF(" padding bytes: %u\n", LOG_VERBOSE(" padding bytes: %u",
buf_size - sizeof(gc_heap_t) - heap_max_size); buf_size - sizeof(gc_heap_t) - heap_max_size);
#endif #endif
return gc_init_internal(heap, base_addr, heap_max_size); return gc_init_internal(heap, base_addr, heap_max_size);
@ -119,11 +119,11 @@ gc_init_with_struct_and_pool(char *struct_buf, gc_size_t struct_buf_size,
heap_max_size = (uint32)(pool_buf_end - base_addr) & (uint32)~7; heap_max_size = (uint32)(pool_buf_end - base_addr) & (uint32)~7;
#if WASM_ENABLE_MEMORY_TRACING != 0 #if WASM_ENABLE_MEMORY_TRACING != 0
MEM_PROF_PRINTF("Heap created, total size: %u\n", LOG_VERBOSE("Heap created, total size: %u",
struct_buf_size + pool_buf_size); struct_buf_size + pool_buf_size);
MEM_PROF_PRINTF(" heap struct size: %u\n", sizeof(gc_heap_t)); LOG_VERBOSE(" heap struct size: %u", sizeof(gc_heap_t));
MEM_PROF_PRINTF(" actual heap size: %u\n", heap_max_size); LOG_VERBOSE(" actual heap size: %u", heap_max_size);
MEM_PROF_PRINTF(" padding bytes: %u\n", pool_buf_size - heap_max_size); LOG_VERBOSE(" padding bytes: %u", pool_buf_size - heap_max_size);
#endif #endif
return gc_init_internal(heap, base_addr, heap_max_size); return gc_init_internal(heap, base_addr, heap_max_size);
} }

View File

@ -87,18 +87,6 @@ bh_log_proc_mem(const char *function, uint32 line);
#define LOG_PROC_MEM(...) bh_log_proc_mem(__FUNCTION__, __LINE__) #define LOG_PROC_MEM(...) bh_log_proc_mem(__FUNCTION__, __LINE__)
/*
* MEM_PROF_PRINTF: output macro for memory profiling/tracing.
* When WASM_MEM_PROFILING_USE_LOG is enabled, routes output through
* LOG_VERBOSE (respects log level filtering, adds timestamps).
* Otherwise, uses os_printf for direct output (original behavior).
*/
#if WASM_MEM_PROFILING_USE_LOG != 0
#define MEM_PROF_PRINTF(...) LOG_VERBOSE(__VA_ARGS__)
#else
#define MEM_PROF_PRINTF(...) os_printf(__VA_ARGS__)
#endif
#ifdef __cplusplus #ifdef __cplusplus
} }
#endif #endif

View File

@ -48,7 +48,7 @@ bh_read_file_to_buffer(const char *filename, uint32 *ret_size)
return NULL; return NULL;
} }
#if WASM_ENABLE_MEMORY_TRACING != 0 #if WASM_ENABLE_MEMORY_TRACING != 0
MEM_PROF_PRINTF("Read file, total size: %u\n", file_size); LOG_VERBOSE("Read file, total size: %u", file_size);
#endif #endif
read_size = _read(file, buffer, file_size); read_size = _read(file, buffer, file_size);
@ -99,7 +99,7 @@ bh_read_file_to_buffer(const char *filename, uint32 *ret_size)
return NULL; return NULL;
} }
#if WASM_ENABLE_MEMORY_TRACING != 0 #if WASM_ENABLE_MEMORY_TRACING != 0
MEM_PROF_PRINTF("Read file, total size: %u\n", file_size); LOG_VERBOSE("Read file, total size: %u", file_size);
#endif #endif
read_size = (uint32)read(file, buffer, file_size); read_size = (uint32)read(file, buffer, file_size);

View File

@ -79,7 +79,6 @@ add_library(vmlib ${WAMR_RUNTIME_LIB_SOURCE})
| [WAMR_BUILD_LOAD_CUSTOM_SECTION](#load-wasm-custom-sections) | loading custom sections | | [WAMR_BUILD_LOAD_CUSTOM_SECTION](#load-wasm-custom-sections) | loading custom sections |
| [WAMR_BUILD_MEMORY64](#memory64-feature) | memory64 support | | [WAMR_BUILD_MEMORY64](#memory64-feature) | memory64 support |
| [WAMR_BUILD_MEMORY_PROFILING](#memory-profiling-experiment) | memory profiling | | [WAMR_BUILD_MEMORY_PROFILING](#memory-profiling-experiment) | memory profiling |
| [WAMR_BUILD_MEM_PROFILING_USE_LOG](#memory-profiling-structured-logging) | memory profiling structured logging |
| [WAMR_BUILD_MEMORY_TRACING](#memory-tracing) | memory tracing | | [WAMR_BUILD_MEMORY_TRACING](#memory-tracing) | memory tracing |
| [WAMR_BUILD_MINI_LOADER](#wasm-mini-loader) :warning: :exclamation: | mini loader | | [WAMR_BUILD_MINI_LOADER](#wasm-mini-loader) :warning: :exclamation: | mini loader |
| [WAMR_BUILD_MODULE_INST_CONTEXT](#module-instance-context-apis) | module instance context | | [WAMR_BUILD_MODULE_INST_CONTEXT](#module-instance-context-apis) | module instance context |
@ -386,13 +385,6 @@ SIMDE (SIMD Everywhere) implements SIMD operations in fast interpreter mode.
> [!NOTE] > [!NOTE]
> When enabled, call `void wasm_runtime_dump_mem_consumption(wasm_exec_env_t exec_env)` to dump memory usage. Currently only module, module_instance, and exec_env memory are measured; other components such as `wasi-ctx`, `multi-module`, and `thread-manager` are not included. See [Memory usage estimation for a module](./memory_usage.md). > When enabled, call `void wasm_runtime_dump_mem_consumption(wasm_exec_env_t exec_env)` to dump memory usage. Currently only module, module_instance, and exec_env memory are measured; other components such as `wasi-ctx`, `multi-module`, and `thread-manager` are not included. See [Memory usage estimation for a module](./memory_usage.md).
### **memory profiling structured logging**
- **WAMR_BUILD_MEM_PROFILING_USE_LOG**=1/0, default to off.
> [!NOTE]
> When enabled, memory profiling and tracing output uses structured logging (`LOG_VERBOSE`) instead of `os_printf`. Output then respects the log verbose level set by `bh_log_set_verbose_level()` and includes timestamps.
### **memory tracing** ### **memory tracing**
- **WAMR_BUILD_MEMORY_TRACING**=1/0, default to off. - **WAMR_BUILD_MEMORY_TRACING**=1/0, default to off.