Profile cold unit module loading

This commit is contained in:
udo
2026-07-16 19:57:40 +00:00
parent 91074ccec9
commit 11025ab8b3
5 changed files with 83 additions and 6 deletions
+73 -5
View File
@@ -103,6 +103,17 @@ struct WasmUnitModule
size_t got_memory_imports = 0;
};
struct WasmUnitModuleLoadProfile
{
bool cache_hit = false;
bool serialized_cache_hit = false;
u64 lookup_us = 0;
u64 read_us = 0;
u64 parse_us = 0;
u64 compile_us = 0;
u64 classify_us = 0;
};
struct WasmWorkerConfig
{
String core_wasm_path = "bin/wasm/core.wasm";
@@ -141,6 +152,15 @@ struct WasmRequestProfile
u64 component_link_total_us = 0;
u64 unit_load_count = 0;
u64 unit_module_total_us = 0;
u64 unit_module_cache_hit_count = 0;
u64 unit_module_cache_miss_count = 0;
u64 unit_module_serialized_cache_hit_count = 0;
u64 unit_module_compile_count = 0;
u64 unit_module_lookup_total_us = 0;
u64 unit_module_read_total_us = 0;
u64 unit_module_parse_total_us = 0;
u64 unit_module_compile_total_us = 0;
u64 unit_module_classify_total_us = 0;
u64 unit_allocate_total_us = 0;
u64 unit_import_total_us = 0;
u64 unit_symbol_resolve_count = 0;
@@ -730,7 +750,8 @@ public:
String core_cached_path = cached_wasm_path(cfg.core_wasm_path);
String compile_error;
auto compiled_or_cached = load_or_compile_cached_module(engine, core_cached_path, cfg.core_wasm_path, bytes, compile_error);
bool serialized_cache_hit = false;
auto compiled_or_cached = load_or_compile_cached_module(engine, core_cached_path, cfg.core_wasm_path, bytes, compile_error, serialized_cache_hit);
if(!compiled_or_cached)
return("core module compile failed: " + compile_error);
core_module.emplace(std::move(*compiled_or_cached));
@@ -747,20 +768,28 @@ public:
return(cfg.cache_root + source_path + ".wasm");
}
std::shared_ptr<WasmUnitModule> unit_module(const String& source_path, String& error)
std::shared_ptr<WasmUnitModule> unit_module(const String& source_path, String& error, WasmUnitModuleLoadProfile& profile)
{
auto lookup_start = std::chrono::steady_clock::now();
String wasm_path = unit_wasm_path(source_path);
struct stat st;
if(stat(wasm_path.c_str(), &st) != 0)
{
profile.lookup_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - lookup_start).count();
error = "no wasm artifact for " + source_path + " (expected " + wasm_path + ")";
return(nullptr);
}
auto cached = module_cache.find(wasm_path);
u64 modified_ns = (u64)st.st_mtim.tv_sec * 1000000000ull + (u64)st.st_mtim.tv_nsec;
u64 changed_ns = (u64)st.st_ctim.tv_sec * 1000000000ull + (u64)st.st_ctim.tv_nsec;
profile.lookup_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - lookup_start).count();
if(cached != module_cache.end() && cached->second->modified_ns == modified_ns && cached->second->changed_ns == changed_ns && cached->second->size == (u64)st.st_size)
{
profile.cache_hit = true;
return(cached->second);
}
auto unit = std::make_shared<WasmUnitModule>();
unit->source_path = source_path;
@@ -769,16 +798,26 @@ public:
unit->changed_ns = changed_ns;
unit->size = (u64)st.st_size;
std::vector<u8> bytes;
auto read_start = std::chrono::steady_clock::now();
if(!wasm_read_file(wasm_path, bytes))
{
profile.read_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - read_start).count();
error = "cannot read " + wasm_path;
return(nullptr);
}
profile.read_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - read_start).count();
auto parse_start = std::chrono::steady_clock::now();
if(!wasm_parse_sections(bytes, unit->dylink, unit->abi, error))
{
profile.parse_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - parse_start).count();
error = wasm_path + ": " + error;
return(nullptr);
}
profile.parse_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - parse_start).count();
if(!unit->dylink.found)
{
error = wasm_path + ": missing dylink.0 mem_info (not a PIC side module)";
@@ -791,13 +830,17 @@ public:
}
String unit_cached_path = cached_wasm_path(wasm_path);
String compile_error;
auto compiled_or_cached = load_or_compile_cached_module(engine, unit_cached_path, wasm_path, bytes, compile_error);
auto compile_start = std::chrono::steady_clock::now();
auto compiled_or_cached = load_or_compile_cached_module(engine, unit_cached_path, wasm_path, bytes, compile_error, profile.serialized_cache_hit);
profile.compile_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - compile_start).count();
if(!compiled_or_cached)
{
error = wasm_path + ": compile failed: " + compile_error;
return(nullptr);
}
unit->module.emplace(std::move(*compiled_or_cached));
auto classify_start = std::chrono::steady_clock::now();
for(auto import_type : unit->module->imports())
{
String mod_name(import_type.module());
@@ -831,6 +874,8 @@ public:
}
unit->imports.push_back({ kind, std::move(name) });
}
profile.classify_us = (u64)std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now() - classify_start).count();
module_cache[wasm_path] = unit;
return(unit);
}
@@ -844,8 +889,9 @@ private:
}
static std::optional<wasmtime::Module> load_or_compile_cached_module(wasmtime::Engine& engine, const String& cached_path, const String& wasm_path,
std::vector<u8>& bytes, String& compile_error)
std::vector<u8>& bytes, String& compile_error, bool& serialized_cache_hit)
{
serialized_cache_hit = false;
struct stat wasm_stat;
struct stat cached_stat;
if(stat(cached_path.c_str(), &cached_stat) == 0 && stat(wasm_path.c_str(), &wasm_stat) == 0)
@@ -855,7 +901,10 @@ private:
{
auto deserialized = wasmtime::Module::deserialize_file(engine, cached_path);
if(deserialized)
{
serialized_cache_hit = true;
return(deserialized.ok());
}
}
}
@@ -1338,9 +1387,19 @@ private:
unit_load_count++;
String error;
auto module_start = std::chrono::steady_clock::now();
auto mod = worker.unit_module(source_path, error);
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>(
std::chrono::steady_clock::now() - module_start).count();
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;
unit_module_compile_count += !module_profile.cache_hit && !module_profile.serialized_cache_hit ? 1 : 0;
unit_module_lookup_total_us += module_profile.lookup_us;
unit_module_read_total_us += module_profile.read_us;
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(!mod)
return(error);
// Compiling/deserializing a cold module is host work. Refresh the guest
@@ -1977,6 +2036,15 @@ private:
response["component_link_us"] = (f64)self->component_link_total_us;
response["unit_load_count"] = (f64)self->unit_load_count;
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;
response["unit_module_serialized_cache_hit_count"] = (f64)self->unit_module_serialized_cache_hit_count;
response["unit_module_compile_count"] = (f64)self->unit_module_compile_count;
response["unit_module_lookup_us"] = (f64)self->unit_module_lookup_total_us;
response["unit_module_read_us"] = (f64)self->unit_module_read_total_us;
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_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;