udo/uce
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Profile unit symbol resolution cost

Browse Source
This commit is contained in:
udo
2026-07-16 18:30:11 +00:00
parent ab3e4dac2e
commit 9c15d6d85d
4 changed files with 25 additions and 3 deletions
Download Patch File Download Diff File Expand all files Collapse all files
site/demo/index.uce
+1
View File
@@ -104,6 +104,7 @@ RENDER(Request& context)
print("Component resolves: ", (u64)perf["component_resolve_count"].to_u64(), " / ", (u64)perf["component_resolve_us"].to_u64(), " us\n");
print("Component phases: path ", (u64)perf["component_path_us"].to_u64(), " / artifact ", (u64)perf["component_artifact_us"].to_u64(), " / load ", (u64)perf["component_load_us"].to_u64(), " / link ", (u64)perf["component_link_us"].to_u64(), " us\n");
print("Unit loads: ", (u64)perf["unit_load_count"].to_u64(), " / module ", (u64)perf["unit_module_us"].to_u64(), " / allocate ", (u64)perf["unit_allocate_us"].to_u64(), " / imports ", (u64)perf["unit_import_us"].to_u64(), " / instantiate ", (u64)perf["unit_instantiate_us"].to_u64(), " / initialize ", (u64)perf["unit_initialize_us"].to_u64(), " us\n");
print("Unit symbol resolves: ", (u64)perf["unit_symbol_resolve_count"].to_u64(), " / ", (u64)perf["unit_symbol_resolve_us"].to_u64(), " us\n");
print("Output buffer size: ", context.ob->str().length(), "\n");
?></pre>
</div>
site/doc/pages/request_perf.txt
+2
View File
@@ -15,6 +15,8 @@ Component resolution is divided into `component_path_us`, `component_artifact_us
Successful first loads within the request are counted by `unit_load_count` and divided into `unit_module_us`, `unit_allocate_us`, `unit_import_us`, `unit_instantiate_us`, and `unit_initialize_us`. These cover compiled-module lookup, guest memory/table allocation, import construction, Wasmtime instantiation, and relocations/constructors/request binding. Repeated handlers from an already loaded unit are excluded.
`unit_symbol_resolve_count` and `unit_symbol_resolve_us` isolate function and data symbol lookup within `unit_import_us`. The remainder of import time covers import-vector construction, Wasmtime Globals, GOT function table placement, and related bindings.
Wasm FastCGI workers retain up to `MYSQL_PERSISTENT_POOL_SIZE` credential-keyed MySQL connections (default `8`; set `0` to disable). UCE calls the client library's connection-reset operation before another request receives a cached connection, clearing transactions, temporary tables, session variables, and selected databases while avoiding a new authentication handshake. Same-request leases continue to share state until request cleanup.
:example
site/tests/io.uce
+4 -2
View File
@@ -151,7 +151,7 @@ RENDER(Request& context)
check("to_u64() / to_s64() / to_f64() / to_bool()", to_u64(cfg["u64"], 7) == 42 && to_u64(cfg["bad"], 7) == 7 && to_s64(cfg["s64"], 5) == -12 && to_s64(cfg["bad"], 5) == 5 && to_f64(cfg["f64"], 1.0) > 3.49 && to_f64(cfg["bad"], 1.25) == 1.25 && to_bool(cfg["yes"], false) && !to_bool(cfg["no"], true) && !to_bool("unknown", false), var_dump(cfg));
DValue perf = request_perf();
bool perf_stable = perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["dispatch_us"].type != 'S' && perf["workspace_setup_us"].type != 'S' && perf["workspace_birth_us"].type != 'S' && perf["context_apply_us"].type != 'S' && perf["hostcall_count"].to_u64() > 0 && perf["hostcall_us"].type != 'S' && perf["guest_us"].to_f64() > 0 && perf["component_resolve_count"].type != 'S' && perf["component_path_us"].type != 'S' && perf["component_artifact_us"].type != 'S' && perf["component_load_us"].type != 'S' && perf["component_link_us"].type != 'S' && perf["unit_load_count"].to_u64() > 0 && perf["unit_module_us"].type != 'S' && perf["unit_allocate_us"].type != 'S' && perf["unit_import_us"].type != 'S' && perf["unit_instantiate_us"].type != 'S' && perf["unit_initialize_us"].type != 'S';
bool perf_stable = perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["dispatch_us"].type != 'S' && perf["workspace_setup_us"].type != 'S' && perf["workspace_birth_us"].type != 'S' && perf["context_apply_us"].type != 'S' && perf["hostcall_count"].to_u64() > 0 && perf["hostcall_us"].type != 'S' && perf["guest_us"].to_f64() > 0 && perf["component_resolve_count"].type != 'S' && perf["component_path_us"].type != 'S' && perf["component_artifact_us"].type != 'S' && perf["component_load_us"].type != 'S' && perf["component_link_us"].type != 'S' && perf["unit_load_count"].to_u64() > 0 && perf["unit_module_us"].type != 'S' && perf["unit_allocate_us"].type != 'S' && perf["unit_import_us"].type != 'S' && perf["unit_symbol_resolve_count"].type != 'S' && perf["unit_symbol_resolve_us"].type != 'S' && perf["unit_instantiate_us"].type != 'S' && perf["unit_initialize_us"].type != 'S';
u64 profiled_hostcalls = perf["hostcall_count"].to_u64();
f64 profiled_hostcall_us = perf["hostcall_us"].to_f64();
u64 profiled_components = perf["component_resolve_count"].to_u64();
@@ -163,13 +163,15 @@ RENDER(Request& context)
u64 profiled_unit_module = perf["unit_module_us"].to_u64();
u64 profiled_unit_allocate = perf["unit_allocate_us"].to_u64();
u64 profiled_unit_import = perf["unit_import_us"].to_u64();
u64 profiled_unit_symbol_resolve_count = perf["unit_symbol_resolve_count"].to_u64();
u64 profiled_unit_symbol_resolve = perf["unit_symbol_resolve_us"].to_u64();
u64 profiled_unit_instantiate = perf["unit_instantiate_us"].to_u64();
u64 profiled_unit_initialize = perf["unit_initialize_us"].to_u64();
String profiled_mysql_operations = json_encode(perf["mysql_operations"]);
for(u64 i = 0; i < 512 && perf_stable; i++)
{
perf = request_perf();
perf_stable = perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["dispatch_us"].type != 'S' && perf["workspace_setup_us"].type != 'S' && perf["workspace_birth_us"].type != 'S' && perf["context_apply_us"].type != 'S' && perf["hostcall_count"].to_u64() == profiled_hostcalls && perf["hostcall_us"].to_f64() == profiled_hostcall_us && perf["guest_us"].to_f64() > 0 && perf["component_resolve_count"].to_u64() == profiled_components && perf["component_path_us"].to_u64() == profiled_component_path && perf["component_artifact_us"].to_u64() == profiled_component_artifact && perf["component_load_us"].to_u64() == profiled_component_load && perf["component_link_us"].to_u64() == profiled_component_link && perf["unit_load_count"].to_u64() == profiled_unit_loads && perf["unit_module_us"].to_u64() == profiled_unit_module && perf["unit_allocate_us"].to_u64() == profiled_unit_allocate && perf["unit_import_us"].to_u64() == profiled_unit_import && perf["unit_instantiate_us"].to_u64() == profiled_unit_instantiate && perf["unit_initialize_us"].to_u64() == profiled_unit_initialize && json_encode(perf["mysql_operations"]) == profiled_mysql_operations;
perf_stable = perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["dispatch_us"].type != 'S' && perf["workspace_setup_us"].type != 'S' && perf["workspace_birth_us"].type != 'S' && perf["context_apply_us"].type != 'S' && perf["hostcall_count"].to_u64() == profiled_hostcalls && perf["hostcall_us"].to_f64() == profiled_hostcall_us && perf["guest_us"].to_f64() > 0 && perf["component_resolve_count"].to_u64() == profiled_components && perf["component_path_us"].to_u64() == profiled_component_path && perf["component_artifact_us"].to_u64() == profiled_component_artifact && perf["component_load_us"].to_u64() == profiled_component_load && perf["component_link_us"].to_u64() == profiled_component_link && perf["unit_load_count"].to_u64() == profiled_unit_loads && perf["unit_module_us"].to_u64() == profiled_unit_module && perf["unit_allocate_us"].to_u64() == profiled_unit_allocate && perf["unit_import_us"].to_u64() == profiled_unit_import && perf["unit_symbol_resolve_count"].to_u64() == profiled_unit_symbol_resolve_count && perf["unit_symbol_resolve_us"].to_u64() == profiled_unit_symbol_resolve && perf["unit_instantiate_us"].to_u64() == profiled_unit_instantiate && perf["unit_initialize_us"].to_u64() == profiled_unit_initialize && json_encode(perf["mysql_operations"]) == profiled_mysql_operations;
}
check("request_perf() stages stable repeated snapshots", perf_stable, json_encode(perf));
src/wasm/worker.cpp
+18 -1
View File
@@ -123,6 +123,8 @@ struct WasmRequestProfile
u64 unit_module_total_us = 0;
u64 unit_allocate_total_us = 0;
u64 unit_import_total_us = 0;
u64 unit_symbol_resolve_count = 0;
u64 unit_symbol_resolve_total_us = 0;
u64 unit_instantiate_total_us = 0;
u64 unit_initialize_total_us = 0;
u64 hostcall_count = 0;
@@ -1357,7 +1359,11 @@ private:
}
if(mod_name == "env" && is_func_import)
{
auto resolve_start = std::chrono::steady_clock::now();
auto func = resolve_func(name);
unit_symbol_resolve_count++;
unit_symbol_resolve_total_us += (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - resolve_start).count();
if(!func)
return(source_path + ": unresolved import env." + wasm_trace_demangle(name));
imports.push_back(*func);
@@ -1367,7 +1373,12 @@ private:
{
wasmtime::GlobalType global_type(wasmtime::ValType::i32(), true);
u32 address = 0;
if(resolve_data(name, address))
auto resolve_start = std::chrono::steady_clock::now();
bool resolved = resolve_data(name, address);
unit_symbol_resolve_count++;
unit_symbol_resolve_total_us += (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - resolve_start).count();
if(resolved)
{
auto global = wasmtime::Global::create(cx, global_type, wasmtime::Val((int32_t)address));
if(!global)
@@ -1388,7 +1399,11 @@ private:
}
if(mod_name == "GOT.func")
{
auto resolve_start = std::chrono::steady_clock::now();
auto func = resolve_func(name);
unit_symbol_resolve_count++;
unit_symbol_resolve_total_us += (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - resolve_start).count();
if(!func)
return(source_path + ": unresolved GOT.func." + wasm_trace_demangle(name));
u32 slot = 0;
@@ -1915,6 +1930,8 @@ private:
response["unit_module_us"] = (f64)self->unit_module_total_us;
response["unit_allocate_us"] = (f64)self->unit_allocate_total_us;
response["unit_import_us"] = (f64)self->unit_import_total_us;
response["unit_symbol_resolve_count"] = (f64)self->unit_symbol_resolve_count;
response["unit_symbol_resolve_us"] = (f64)self->unit_symbol_resolve_total_us;
response["unit_instantiate_us"] = (f64)self->unit_instantiate_total_us;
response["unit_initialize_us"] = (f64)self->unit_initialize_total_us;
f64 running_us = response["running_us"].to_f64();