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

Profile entry and component materialization

Browse Source
This commit is contained in:
root 2026-07-17 18:28:49 +00:00
parent 3e423f49dd
commit 556bb06f81
4 changed files with 40 additions and 4 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
site/doc/pages/mysql_connected.txt
View File

@ -17,4 +17,5 @@ if(!mysql_connected(db))
{
print("database unavailable: ", mysql_error(db), "\n");
}
else print("database connected\n");
if(db != 0) mysql_disconnect(db);

2
site/doc/pages/request_perf.txt
View File

@ -15,7 +15,7 @@ Hostcall totals include component resolution. When `WASM_PROFILE_HOSTCALL_CPU=1`
Component resolution is divided into `component_path_us`, `component_artifact_us`, `component_load_us`, and `component_link_us`. These aggregate path resolution, artifact readiness/freshness, Wasmtime side-module loading, and exported-handler lookup/table placement without exposing source paths.
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.
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. `entry_unit_load_count` and `entry_unit_materialize_us` isolate the initial page/CLI unit; `dynamic_include_load_count` and `dynamic_include_materialize_us` isolate side units first requested through `component()`. The per-unit bounded list adds `kind` (`entry` or `component`) and `materialize_us`, the inclusive host-side time from module acquisition through request binding. Repeated handlers from an already loaded unit are excluded.
`unit_module_cache_hit_count` and `unit_module_cache_miss_count` divide module loads by the worker's compiled-module cache. A miss is further identified by `unit_module_serialized_cache_hit_count` when Wasmtime deserializes the current `.cwasm`; `unit_module_compile_count` means it fell back to compiling the `.wasm`. `unit_module_lookup_us`, `unit_module_read_us`, `unit_module_read_bytes`, `unit_module_parse_us`, `unit_module_compile_us`, and `unit_module_classify_us` divide `unit_module_us` into artifact stat/cache lookup, wasm metadata/full-artifact read volume, custom-section parse, deserialize-or-compile, and immutable import classification. A current serialized-module hit scans only section headers and the `dylink.0`/`uce.abi` payloads; compilation fallback reads the complete wasm. The phase sum can be below the total because allocation and cache publication overhead remain in the aggregate.

7
site/tests/components.uce
View File

@ -55,6 +55,13 @@ RENDER(Request& context)
check("component_render() named handler", footer_markup.find("Named footer render") != String::npos, footer_markup);
check("component(\"unit:NAME\") named handler", header_markup.find("Component Output") != String::npos && header_markup.find("This body comes from component()") == String::npos, header_markup);
check("ob_start() / ob_get_close()", buffer_markup == "buffered-text", buffer_markup);
DValue perf = request_perf();
String unit_operations = json_encode(perf["unit_module_operations"]);
check(
"request_perf() separates entry code from dynamic component materialization",
perf["entry_unit_load_count"].to_u64() == 1 && perf["entry_unit_materialize_us"].to_u64() > 0 && perf["dynamic_include_load_count"].to_u64() > 0 && perf["dynamic_include_materialize_us"].to_u64() > 0 && unit_operations.find("\"kind\": \"entry\"") != String::npos && unit_operations.find("\"kind\": \"component\"") != String::npos && unit_operations.find("\"materialize_us\"") != String::npos,
unit_operations
);
?><div class="tests-section">
<h3>Rendered Component</h3>

34
src/wasm/worker.cpp
View File

@ -146,8 +146,10 @@ struct WasmMySQLOperation
struct WasmUnitModuleOperation
{
String unit;
String kind;
String source;
u64 total_us = 0;
u64 materialize_us = 0;
u64 lookup_us = 0;
u64 read_us = 0;
u64 read_bytes = 0;
@ -179,6 +181,10 @@ struct WasmRequestProfile
u64 component_load_total_us = 0;
u64 component_link_total_us = 0;
u64 unit_load_count = 0;
u64 entry_unit_load_count = 0;
u64 entry_unit_materialize_total_us = 0;
u64 dynamic_include_load_count = 0;
u64 dynamic_include_materialize_total_us = 0;
u64 unit_module_total_us = 0;
u64 unit_module_cache_hit_count = 0;
u64 unit_module_cache_miss_count = 0;
@ -1417,7 +1423,7 @@ public:
{
entry_dir = dir_of(entry_source_path);
size_t unit_index = 0;
String error = load_unit(entry_source_path, unit_index);
String error = load_unit(entry_source_path, "entry", unit_index);
if(error != "")
return(error);
bool present = (bool)unit_func(unit_index, handler_export_symbol(handler));
@ -1630,7 +1636,7 @@ private:
// ---- unit loading (the §6 sequence) ------------------------------------
String load_unit(const String& source_path, size_t& unit_index_out)
String load_unit(const String& source_path, String kind, size_t& unit_index_out)
{
auto known = units_by_source.find(source_path);
if(known != units_by_source.end())
@ -1640,6 +1646,7 @@ private:
}
unit_load_count++;
auto materialize_start = std::chrono::steady_clock::now();
String error;
auto module_start = std::chrono::steady_clock::now();
WasmUnitModuleLoadProfile module_profile;
@ -1670,6 +1677,7 @@ private:
unit_name = unit_name.substr(unit_name.rfind('/') + 1);
WasmUnitModuleOperation operation;
operation.unit = unit_name;
operation.kind = kind;
operation.source = !mod ? "error" : module_profile.cache_hit ? "worker" : module_profile.serialized_cache_hit ? "serialized" : "compiled";
operation.total_us = module_total_us;
operation.lookup_us = module_profile.lookup_us;
@ -1888,6 +1896,20 @@ private:
unit_initialize_total_us += initialize_us;
if(module_operation_index < unit_module_operations.size())
unit_module_operations[module_operation_index].initialize_us = initialize_us;
u64 materialize_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - materialize_start).count();
if(kind == "entry")
{
entry_unit_load_count++;
entry_unit_materialize_total_us += materialize_us;
}
else if(kind == "component")
{
dynamic_include_load_count++;
dynamic_include_materialize_total_us += materialize_us;
}
if(module_operation_index < unit_module_operations.size())
unit_module_operations[module_operation_index].materialize_us = materialize_us;
// Exclude the rest of host-side loading as well. A genuine runaway loop
// makes no loads, so it still trips the deadline.
ctx().set_epoch_deadline(worker.cfg.epoch_deadline_ticks);
@ -2166,7 +2188,7 @@ private:
auto load_start = std::chrono::steady_clock::now();
size_t unit_index = 0;
String error = load_unit(resolved, unit_index);
String error = load_unit(resolved, "component", unit_index);
component_load_total_us += (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - load_start).count();
if(error != "")
@ -2424,6 +2446,10 @@ private:
response["component_load_us"] = (f64)self->component_load_total_us;
response["component_link_us"] = (f64)self->component_link_total_us;
response["unit_load_count"] = (f64)self->unit_load_count;
response["entry_unit_load_count"] = (f64)self->entry_unit_load_count;
response["entry_unit_materialize_us"] = (f64)self->entry_unit_materialize_total_us;
response["dynamic_include_load_count"] = (f64)self->dynamic_include_load_count;
response["dynamic_include_materialize_us"] = (f64)self->dynamic_include_materialize_total_us;
response["unit_module_us"] = (f64)self->unit_module_total_us;
response["unit_module_cache_hit_count"] = (f64)self->unit_module_cache_hit_count;
response["unit_module_cache_miss_count"] = (f64)self->unit_module_cache_miss_count;
@ -2441,8 +2467,10 @@ private:
{
DValue item;
item["unit"] = operation.unit;
item["kind"] = operation.kind;
item["source"] = operation.source;
item["total_us"] = (f64)operation.total_us;
item["materialize_us"] = (f64)operation.materialize_us;
item["lookup_us"] = (f64)operation.lookup_us;
item["read_us"] = (f64)operation.read_us;
item["read_bytes"] = (f64)operation.read_bytes;