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

Expose per-unit module request profiles

Browse Source
This commit is contained in:
udo 2026-07-16 22:32:30 +00:00
parent b4f652b5a5
commit a247c2b520
3 changed files with 68 additions and 2 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

6
docs/wasm-runtime-architecture.md
View File

@ -169,7 +169,11 @@ hostcalls without per-import timeout bookkeeping.
`request_perf()` reports worker module-cache hits and misses and divides a miss
into artifact lookup, wasm read, custom-section parse, serialized-module
deserialization or wasm compilation, and immutable import classification. This
keeps cold-worker module latency distinguishable without exposing source paths.
includes a bounded per-request unit trace with site-relative unit names, cache
source, bytes, and phase durations so a cold outlier identifies its exact unit
and whether it used worker memory, serialized code, compilation, or failed.
Absolute source paths and source contents are not exposed. This keeps cold-worker
module latency distinguishable without exposing source paths.
When a current serialized module exists, the worker scans wasm section headers
and reads only `dylink.0` and `uce.abi`; it does not fault the multi-megabyte code
and data bodies into every new worker. A missing/stale/invalid serialized module

6
site/tests/services.uce
View File

@ -147,11 +147,17 @@ RENDER(Request& context)
}
DValue mysql_perf = request_perf();
String mysql_operations = json_encode(mysql_perf["mysql_operations"]);
String unit_module_operations = json_encode(mysql_perf["unit_module_operations"]);
mark(
"request_perf() exposes bounded query-text-free MySQL operations",
mysql_perf["mysql_operation_count"].to_u64() > 0 && mysql_operations.find("\"connect\"") != String::npos && mysql_operations.find("\"source\"") != String::npos && mysql_operations.find("\"us\"") != String::npos && mysql_operations.find("SHOW DATABASES") == String::npos && (mysql_error_text != "" || mysql_perf["mysql_connection_open_count"].to_u64() + mysql_perf["mysql_connection_reuse_count"].to_u64() > 0) && mysql_perf["mysql_operations_dropped"].to_u64() == 0 ? "pass" : "fail",
mysql_operations
);
mark(
"request_perf() identifies bounded site-relative unit module work",
unit_module_operations != "[]" && unit_module_operations.find("services.uce") != String::npos && unit_module_operations.find("\"source\"") != String::npos && unit_module_operations.find("/Code/") == String::npos && mysql_perf["unit_module_operations_dropped"].to_u64() == 0 ? "pass" : "fail",
unit_module_operations
);
site_tests_summary(passed, failed, skipped, "Memcache or MySQL checks are allowed to skip cleanly when the corresponding service is not available on the development host.");
site_tests_page_end();

58
src/wasm/worker.cpp
View File

@ -139,6 +139,19 @@ struct WasmMySQLOperation
u64 elapsed_us = 0;
};
struct WasmUnitModuleOperation
{
String unit;
String source;
u64 total_us = 0;
u64 lookup_us = 0;
u64 read_us = 0;
u64 read_bytes = 0;
u64 parse_us = 0;
u64 build_us = 0;
u64 classify_us = 0;
};
struct WasmRequestProfile
{
u64 dispatch_us = 0;
@ -163,6 +176,8 @@ struct WasmRequestProfile
u64 unit_module_parse_total_us = 0;
u64 unit_module_compile_total_us = 0;
u64 unit_module_classify_total_us = 0;
u64 unit_module_operations_dropped = 0;
std::vector<WasmUnitModuleOperation> unit_module_operations;
u64 unit_allocate_total_us = 0;
u64 unit_import_total_us = 0;
u64 unit_symbol_resolve_count = 0;
@ -1561,8 +1576,9 @@ private:
auto module_start = std::chrono::steady_clock::now();
WasmUnitModuleLoadProfile module_profile;
auto mod = worker.unit_module(source_path, error, module_profile);
unit_module_total_us += (u64)std::chrono::duration_cast<std::chrono::microseconds>(
u64 module_total_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - module_start).count();
unit_module_total_us += module_total_us;
unit_module_cache_hit_count += module_profile.cache_hit ? 1 : 0;
unit_module_cache_miss_count += module_profile.cache_hit ? 0 : 1;
unit_module_serialized_cache_hit_count += module_profile.serialized_cache_hit ? 1 : 0;
@ -1573,6 +1589,30 @@ private:
unit_module_parse_total_us += module_profile.parse_us;
unit_module_compile_total_us += module_profile.compile_us;
unit_module_classify_total_us += module_profile.classify_us;
if(unit_module_operations.size() < 32)
{
String unit_name = source_path;
String site_prefix = worker.cfg.site_root;
if(site_prefix != "" && site_prefix.back() != '/')
site_prefix += "/";
if(site_prefix != "" && unit_name.rfind(site_prefix, 0) == 0)
unit_name = unit_name.substr(site_prefix.size());
else if(unit_name.rfind('/') != String::npos)
unit_name = unit_name.substr(unit_name.rfind('/') + 1);
WasmUnitModuleOperation operation;
operation.unit = unit_name;
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;
operation.read_us = module_profile.read_us;
operation.read_bytes = module_profile.read_bytes;
operation.parse_us = module_profile.parse_us;
operation.build_us = module_profile.compile_us;
operation.classify_us = module_profile.classify_us;
unit_module_operations.push_back(operation);
}
else
unit_module_operations_dropped++;
if(!mod)
return(error);
// Compiling/deserializing a cold module is host work. Refresh the guest
@ -2230,6 +2270,22 @@ private:
response["unit_module_parse_us"] = (f64)self->unit_module_parse_total_us;
response["unit_module_compile_us"] = (f64)self->unit_module_compile_total_us;
response["unit_module_classify_us"] = (f64)self->unit_module_classify_total_us;
response["unit_module_operations_dropped"] = (f64)self->unit_module_operations_dropped;
response["unit_module_operations"].set_array();
for(auto& operation : self->unit_module_operations)
{
DValue item;
item["unit"] = operation.unit;
item["source"] = operation.source;
item["total_us"] = (f64)operation.total_us;
item["lookup_us"] = (f64)operation.lookup_us;
item["read_us"] = (f64)operation.read_us;
item["read_bytes"] = (f64)operation.read_bytes;
item["parse_us"] = (f64)operation.parse_us;
item["build_us"] = (f64)operation.build_us;
item["classify_us"] = (f64)operation.classify_us;
response["unit_module_operations"].push(item);
}
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;