Cache positive entry freshness checks

This commit is contained in:
udo
2026-07-19 04:24:45 +00:00
parent d95fb38183
commit 4f010d37a0
8 changed files with 332 additions and 11 deletions
+13 -6
View File
@@ -229,12 +229,19 @@ and whether it used worker memory, serialized code, compilation, or failed.
Absolute source paths and source contents are not exposed. This keeps cold-worker Absolute source paths and source contents are not exposed. This keeps cold-worker
module latency distinguishable without exposing source paths. module latency distinguishable without exposing source paths.
The same snapshot divides pre-dispatch WASM readiness into entry normalization, The same snapshot divides pre-dispatch WASM readiness into entry normalization,
mutation freshness, artifact stat, complete dependency freshness, and worker mutation freshness, artifact stat, source-generation lookup, dependency
availability. `ready_check_count` distinguishes the warm one-check path from an freshness, and worker availability. `ready_freshness_full_check_us` and
on-demand compile and recheck; repeated snapshot reads retain the initial values. `ready_freshness_cache_hit_count` distinguish full graph validation from a
Freshness still stats every distinct source on every entry check. Exact repeated positive worker-local hit; `ready_freshness_us` remains inclusive.
load paths are deduplicated before canonicalization, while distinct aliases are `ready_check_count` distinguishes the warm one-check path from an on-demand
resolved independently so symlink retargets remain immediately visible. compile and recheck; repeated snapshot reads retain the initial values.
Read-only HTTP entry checks may reuse a positive result for at most ten seconds
when the source generation and exact Wasm, metadata, and setup-template
identities are unchanged. CLI and mutation requests always validate the complete
graph. Misses, expiry, missing tokens, and changed identities also run the full
check. Exact repeated load paths are then deduplicated before canonicalization,
while distinct aliases are resolved independently so symlink retargets remain
visible by the next hard validation.
When a current serialized module exists, the worker scans wasm section headers When a current serialized module exists, the worker scans wasm section headers
and reads only `dylink.0`, `uce.abi`, and the tiny `uce.module` identity; it does and reads only `dylink.0`, `uce.abi`, and the tiny `uce.module` identity; it does
not fault the code and data bodies into every new worker. A missing/stale/invalid serialized module not fault the code and data bodies into every new worker. A missing/stale/invalid serialized module
+1
View File
@@ -82,6 +82,7 @@ if [[ "$action" == "run" ]]; then
scripts/test_log_timeliness.sh scripts/test_log_timeliness.sh
scripts/test_raw_http_request_log.sh scripts/test_raw_http_request_log.sh
scripts/test_component_resolution_ttl.sh scripts/test_component_resolution_ttl.sh
timeout --signal=TERM --kill-after=5s 120s scripts/test_entry_freshness_ttl.sh
scripts/test_unit_export_surface.sh scripts/test_unit_export_surface.sh
scripts/test_wasm_source_locations.sh scripts/test_wasm_source_locations.sh
scripts/test_socket_activation.sh scripts/test_socket_activation.sh
+175
View File
@@ -0,0 +1,175 @@
#!/usr/bin/env bash
set -euo pipefail
cd "$(dirname "$0")/.."
test_name="entry-freshness-ttl-test-$$"
site_directory="${UCE_TEST_SITE_DIRECTORY:-site}"
worker_count="${UCE_TEST_WORKER_COUNT:-4}"
bin_directory="${BIN_DIRECTORY:-/tmp/uce/work}"
http_host="${UCE_TEST_HTTP_HOST:-uce.openfu.com}"
if [[ -r /etc/uce/settings.cfg ]]; then
configured_site_directory=$(awk -F= '/^[[:space:]]*SITE_DIRECTORY[[:space:]]*=/ {gsub(/^[[:space:]]+|[[:space:]]+$/, "", $2); print $2; exit}' /etc/uce/settings.cfg)
configured_worker_count=$(awk -F= '/^[[:space:]]*WORKER_COUNT[[:space:]]*=/ {gsub(/^[[:space:]]+|[[:space:]]+$/, "", $2); print $2; exit}' /etc/uce/settings.cfg)
configured_bin_directory=$(awk -F= '/^[[:space:]]*BIN_DIRECTORY[[:space:]]*=/ {gsub(/^[[:space:]]+|[[:space:]]+$/, "", $2); print $2; exit}' /etc/uce/settings.cfg)
[[ -n "${UCE_TEST_SITE_DIRECTORY:-}" || -z "$configured_site_directory" ]] || site_directory="$configured_site_directory"
[[ -n "${UCE_TEST_WORKER_COUNT:-}" || -z "$configured_worker_count" ]] || worker_count="$configured_worker_count"
[[ -n "${BIN_DIRECTORY:-}" || -z "$configured_bin_directory" ]] || bin_directory="$configured_bin_directory"
fi
source_dir="$site_directory/$test_name"
cache_dir=""
mutation_file="/tmp/$test_name-mutation"
post_body="/tmp/$test_name-post-body"
post_headers="/tmp/$test_name-post-headers"
generation_file=""
cleanup() {
if [[ -n "$generation_file" ]]; then
exec 7>"$generation_file.lock"
flock 7
printf 'test-cleanup:%s\n' "$(date +%s%N)" >"$generation_file"
flock -u 7
exec 7>&-
fi
rm -rf "$source_dir"
[[ -z "$cache_dir" ]] || rm -rf "$cache_dir"
rm -f "$mutation_file" "$post_body" "$post_headers"
}
trap cleanup EXIT
mkdir -p "$source_dir"
cache_dir="$(scripts/unit_cache_directory "$bin_directory")$(realpath "$source_dir")"
generation_file="$(scripts/unit_cache_directory "$bin_directory")/source-generation.txt"
printf '%s\n' 'String entry_freshness_marker() { return("marker-a"); }' >"$source_dir/child.uce"
printf '%s\n' \
'#load "child.uce"' \
"void entry_freshness_output(Request& context) { DValue perf = request_perf(); if(context.params[\"REQUEST_METHOD\"] == \"POST\") file_put_contents(\"$mutation_file\", \"executed\"); print(entry_freshness_marker(), \":\", perf[\"worker_pid\"].to_string(), \":\", perf[\"ready_freshness_cache_hit_count\"].to_string(), \":\", perf[\"ready_freshness_full_check_us\"].to_string()); }" \
'RENDER(Request& context) { entry_freshness_output(context); }' \
'CLI(Request& context) { entry_freshness_output(context); }' >"$source_dir/parent.uce"
http_probe() {
curl -fsS --max-time 5 -H "Host: $http_host" "http://127.0.0.1/$test_name/parent.uce"
}
declare -A seen
collect_all_workers() {
local require_hit="$1"
local expected_marker="$2"
local deadline=$((SECONDS + 35))
seen=()
while (( SECONDS < deadline && ${#seen[@]} < worker_count )); do
local output marker pid hit full
output=$(http_probe)
IFS=: read -r marker pid hit full <<<"$output"
pid=${pid%%.*}; hit=${hit%%.*}; full=${full%%.*}
if [[ "$marker" != "$expected_marker" || -z "$pid" ]]; then
echo "entry freshness probe returned unexpected output: $output" >&2
exit 1
fi
if [[ "$require_hit" == "1" && ( "$hit" == "0" || "$full" != "0" ) ]]; then
continue
fi
seen["$pid"]=1
done
if (( ${#seen[@]} != worker_count )); then
echo "entry freshness probe reached ${#seen[@]}/$worker_count workers (hit=$require_hit)" >&2
exit 1
fi
}
collect_all_workers 0 marker-a
collect_all_workers 1 marker-a
parent_wasm="$cache_dir/parent.uce.wasm"
exec 8>"$parent_wasm.lock"
flock 8
sed -i 's/marker-a/marker-b/' "$source_dir/child.uce"
rm -f "$mutation_file"
post_status=$(curl -sS --max-time 5 -o "$post_body" -D "$post_headers" -w '%{http_code}' -X POST -H "Host: $http_host" "http://127.0.0.1/$test_name/parent.uce")
if [[ "$post_status" != "503" || -e "$mutation_file" ]] || ! grep -qi '^Retry-After: 1' "$post_headers"; then
echo "stale mutation did not fail closed: status=$post_status body=$(cat "$post_body")" >&2
exit 1
fi
sleep 10.2
expired_output=$(http_probe)
IFS=: read -r expired_marker expired_pid expired_hit expired_full <<<"$expired_output"
expired_hit=${expired_hit%%.*}; expired_full=${expired_full%%.*}
if [[ "$expired_marker" != "marker-a" || "$expired_hit" != "0" || "$expired_full" == "0" ]]; then
echo "expired positive entry did not perform a full safe check: $expired_output" >&2
exit 1
fi
flock -u 8
exec 8>&-
deadline=$((SECONDS + 25))
output=""
while (( SECONDS < deadline )); do
output=$(http_probe)
[[ "$output" == marker-b:* ]] && break
sleep 0.2
done
if [[ "$output" != marker-b:* ]]; then
echo "entry did not converge after dependency rebuild: $output" >&2
exit 1
fi
collect_all_workers 1 marker-b
exec 9>"$generation_file.lock"
flock 9
printf 'test:%s\n' "$(date +%s%N)" >"$generation_file"
flock -u 9
exec 9>&-
generation_output=$(http_probe)
IFS=: read -r generation_marker generation_pid generation_hit generation_full <<<"$generation_output"
generation_hit=${generation_hit%%.*}; generation_full=${generation_full%%.*}
if [[ "$generation_marker" != "marker-b" || "$generation_hit" != "0" || "$generation_full" == "0" ]]; then
echo "source generation change did not invalidate immediately: $generation_output" >&2
exit 1
fi
collect_all_workers 1 marker-b
touch "$parent_wasm"
identity_output=$(http_probe)
IFS=: read -r identity_marker identity_pid identity_hit identity_full <<<"$identity_output"
identity_hit=${identity_hit%%.*}; identity_full=${identity_full%%.*}
if [[ "$identity_marker" != "marker-b" || "$identity_hit" != "0" || "$identity_full" == "0" ]]; then
echo "wasm identity change did not invalidate immediately: $identity_output" >&2
exit 1
fi
collect_all_workers 1 marker-b
touch "$cache_dir/parent.uce.meta.txt"
metadata_output=$(http_probe)
IFS=: read -r metadata_marker metadata_pid metadata_hit metadata_full <<<"$metadata_output"
metadata_hit=${metadata_hit%%.*}; metadata_full=${metadata_full%%.*}
if [[ "$metadata_marker" != "marker-b" || "$metadata_hit" != "0" || "$metadata_full" == "0" ]]; then
echo "metadata identity change did not invalidate immediately: $metadata_output" >&2
exit 1
fi
collect_all_workers 1 marker-b
exec 9>"$generation_file.lock"
flock 9
rm -f "$generation_file"
flock -u 9
missing_generation_output=$(http_probe)
IFS=: read -r missing_generation_marker missing_generation_pid missing_generation_hit missing_generation_full <<<"$missing_generation_output"
missing_generation_hit=${missing_generation_hit%%.*}; missing_generation_full=${missing_generation_full%%.*}
if [[ "$missing_generation_marker" != "marker-b" || "$missing_generation_hit" != "0" || "$missing_generation_full" == "0" ]]; then
echo "missing generation token did not force a full check: $missing_generation_output" >&2
exit 1
fi
flock 9
printf 'test:%s\n' "$(date +%s%N)" >"$generation_file"
flock -u 9
exec 9>&-
cli_output=$(timeout --signal=TERM --kill-after=3s 20s scripts/uce-cli "/$test_name/parent.uce")
IFS=: read -r cli_marker cli_pid cli_hit cli_full <<<"$cli_output"
cli_hit=${cli_hit%%.*}; cli_full=${cli_full%%.*}
if [[ "$cli_marker" != "marker-b" || "$cli_hit" != "0" || "$cli_full" == "0" ]]; then
echo "CLI unexpectedly reused the HTTP freshness cache: $cli_output" >&2
exit 1
fi
echo "entry freshness TTL passed"
+2
View File
@@ -15,6 +15,8 @@ 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. 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.
Entry readiness reports inclusive `ready_freshness_us` plus `ready_source_generation_us`, `ready_freshness_full_check_us`, and `ready_freshness_cache_hit_count`. Read-only HTTP requests can reuse a positive result for at most ten seconds only while source generation and exact artifact identities remain unchanged. CLI, mutation, miss, expiry, and uncertain states perform the complete dependency check.
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. 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. `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.
+5 -2
View File
@@ -185,11 +185,14 @@ RENDER(Request& context)
u64 dropped_hostcall_operations = perf["hostcall_operations_dropped"].to_u64(); u64 dropped_hostcall_operations = perf["hostcall_operations_dropped"].to_u64();
hostcall_operation_profile_valid = hostcall_operation_profile_valid && perf["hostcall_cpu_profiled"].type == 'B' && perf["hostcall_cpu_us"].to_u64() <= perf["hostcall_us"].to_u64() + 2 && operation_kinds > 0 && operation_kinds <= 32 && ((dropped_hostcall_operations == 0 && operation_hostcalls == perf["hostcall_count"].to_u64() && operation_hostcall_us == perf["hostcall_us"].to_u64() && operation_hostcall_cpu_us == perf["hostcall_cpu_us"].to_u64()) || (dropped_hostcall_operations > 0 && operation_kinds == 32 && operation_hostcalls < perf["hostcall_count"].to_u64() && operation_hostcall_us <= perf["hostcall_us"].to_u64() && operation_hostcall_cpu_us <= perf["hostcall_cpu_us"].to_u64())); hostcall_operation_profile_valid = hostcall_operation_profile_valid && perf["hostcall_cpu_profiled"].type == 'B' && perf["hostcall_cpu_us"].to_u64() <= perf["hostcall_us"].to_u64() + 2 && operation_kinds > 0 && operation_kinds <= 32 && ((dropped_hostcall_operations == 0 && operation_hostcalls == perf["hostcall_count"].to_u64() && operation_hostcall_us == perf["hostcall_us"].to_u64() && operation_hostcall_cpu_us == perf["hostcall_cpu_us"].to_u64()) || (dropped_hostcall_operations > 0 && operation_kinds == 32 && operation_hostcalls < perf["hostcall_count"].to_u64() && operation_hostcall_us <= perf["hostcall_us"].to_u64() && operation_hostcall_cpu_us <= perf["hostcall_cpu_us"].to_u64()));
bool thread_runtime_profile_valid = perf["thread_runtime_profiled"].type == 'B' && (!perf["thread_runtime_profiled"].to_bool() || (perf["thread_cpu_start"].to_f64() >= 0 && perf["thread_cpu_end"].to_f64() >= 0 && perf["thread_cpu_migrated"].type == 'B' && perf["thread_user_cpu_us"].to_u64() + perf["thread_system_cpu_us"].to_u64() <= perf["workspace_wall_us"].to_u64() + 5 && perf["thread_voluntary_context_switches"].type != 'S' && perf["thread_involuntary_context_switches"].type != 'S' && perf["thread_minor_faults"].type != 'S' && perf["thread_major_faults"].type != 'S')); bool thread_runtime_profile_valid = perf["thread_runtime_profiled"].type == 'B' && (!perf["thread_runtime_profiled"].to_bool() || (perf["thread_cpu_start"].to_f64() >= 0 && perf["thread_cpu_end"].to_f64() >= 0 && perf["thread_cpu_migrated"].type == 'B' && perf["thread_user_cpu_us"].to_u64() + perf["thread_system_cpu_us"].to_u64() <= perf["workspace_wall_us"].to_u64() + 5 && perf["thread_voluntary_context_switches"].type != 'S' && perf["thread_involuntary_context_switches"].type != 'S' && perf["thread_minor_faults"].type != 'S' && perf["thread_major_faults"].type != 'S'));
bool perf_stable = transport_profile_valid && workspace_cpu_profile_valid && unit_module_profile_valid && hostcall_operation_profile_valid && thread_runtime_profile_valid && perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["ready_normalize_us"].type != 'S' && perf["ready_mutation_check_us"].type != 'S' && perf["ready_artifact_stat_us"].type != 'S' && perf["ready_freshness_us"].type != 'S' && perf["ready_worker_us"].type != 'S' && perf["ready_check_count"].to_u64() > 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_loaded_reuse_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'; bool perf_stable = transport_profile_valid && workspace_cpu_profile_valid && unit_module_profile_valid && hostcall_operation_profile_valid && thread_runtime_profile_valid && perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["ready_normalize_us"].type != 'S' && perf["ready_mutation_check_us"].type != 'S' && perf["ready_artifact_stat_us"].type != 'S' && perf["ready_freshness_us"].type != 'S' && perf["ready_source_generation_us"].type != 'S' && perf["ready_freshness_full_check_us"].type != 'S' && perf["ready_freshness_cache_hit_count"].type != 'S' && perf["ready_worker_us"].type != 'S' && perf["ready_check_count"].to_u64() > 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_loaded_reuse_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_ready_normalize = perf["ready_normalize_us"].to_u64(); u64 profiled_ready_normalize = perf["ready_normalize_us"].to_u64();
u64 profiled_ready_mutation_check = perf["ready_mutation_check_us"].to_u64(); u64 profiled_ready_mutation_check = perf["ready_mutation_check_us"].to_u64();
u64 profiled_ready_artifact_stat = perf["ready_artifact_stat_us"].to_u64(); u64 profiled_ready_artifact_stat = perf["ready_artifact_stat_us"].to_u64();
u64 profiled_ready_freshness = perf["ready_freshness_us"].to_u64(); u64 profiled_ready_freshness = perf["ready_freshness_us"].to_u64();
u64 profiled_ready_source_generation = perf["ready_source_generation_us"].to_u64();
u64 profiled_ready_freshness_full_check = perf["ready_freshness_full_check_us"].to_u64();
u64 profiled_ready_freshness_cache_hit_count = perf["ready_freshness_cache_hit_count"].to_u64();
u64 profiled_ready_worker = perf["ready_worker_us"].to_u64(); u64 profiled_ready_worker = perf["ready_worker_us"].to_u64();
u64 profiled_ready_checks = perf["ready_check_count"].to_u64(); u64 profiled_ready_checks = perf["ready_check_count"].to_u64();
u64 profiled_hostcalls = perf["hostcall_count"].to_u64(); u64 profiled_hostcalls = perf["hostcall_count"].to_u64();
@@ -214,7 +217,7 @@ RENDER(Request& context)
for(u64 i = 0; i < 512 && perf_stable; i++) for(u64 i = 0; i < 512 && perf_stable; i++)
{ {
perf = request_perf(); perf = request_perf();
perf_stable = perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["ready_normalize_us"].to_u64() == profiled_ready_normalize && perf["ready_mutation_check_us"].to_u64() == profiled_ready_mutation_check && perf["ready_artifact_stat_us"].to_u64() == profiled_ready_artifact_stat && perf["ready_freshness_us"].to_u64() == profiled_ready_freshness && perf["ready_worker_us"].to_u64() == profiled_ready_worker && perf["ready_check_count"].to_u64() == profiled_ready_checks && 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["hostcall_cpu_us"].to_u64() == profiled_hostcall_cpu_us && perf["guest_us"].to_f64() > 0 && perf["component_resolve_count"].to_u64() == profiled_components && perf["component_loaded_reuse_count"].to_u64() == profiled_component_loaded_reuses && 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 && json_encode(perf["hostcall_operations"]) == profiled_hostcall_operations; perf_stable = perf["worker_pid"].to_u64() > 0 && perf["running_us"].to_f64() > 0 && perf["ready_normalize_us"].to_u64() == profiled_ready_normalize && perf["ready_mutation_check_us"].to_u64() == profiled_ready_mutation_check && perf["ready_artifact_stat_us"].to_u64() == profiled_ready_artifact_stat && perf["ready_freshness_us"].to_u64() == profiled_ready_freshness && perf["ready_source_generation_us"].to_u64() == profiled_ready_source_generation && perf["ready_freshness_full_check_us"].to_u64() == profiled_ready_freshness_full_check && perf["ready_freshness_cache_hit_count"].to_u64() == profiled_ready_freshness_cache_hit_count && perf["ready_worker_us"].to_u64() == profiled_ready_worker && perf["ready_check_count"].to_u64() == profiled_ready_checks && 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["hostcall_cpu_us"].to_u64() == profiled_hostcall_cpu_us && perf["guest_us"].to_f64() > 0 && perf["component_resolve_count"].to_u64() == profiled_components && perf["component_loaded_reuse_count"].to_u64() == profiled_component_loaded_reuses && 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 && json_encode(perf["hostcall_operations"]) == profiled_hostcall_operations;
} }
check("request_perf() stages stable repeated snapshots", perf_stable, json_encode(perf)); check("request_perf() stages stable repeated snapshots", perf_stable, json_encode(perf));
+3
View File
@@ -320,8 +320,11 @@ struct Request {
u64 wasm_ready_mutation_check_us = 0; u64 wasm_ready_mutation_check_us = 0;
u64 wasm_ready_artifact_stat_us = 0; u64 wasm_ready_artifact_stat_us = 0;
u64 wasm_ready_freshness_us = 0; u64 wasm_ready_freshness_us = 0;
u64 wasm_ready_source_generation_us = 0;
u64 wasm_ready_freshness_full_check_us = 0;
u64 wasm_ready_worker_us = 0; u64 wasm_ready_worker_us = 0;
u32 wasm_ready_check_count = 0; u32 wasm_ready_check_count = 0;
u32 wasm_ready_freshness_cache_hit_count = 0;
u64 mem_high = 0; u64 mem_high = 0;
u64 mem_alloc = 0; u64 mem_alloc = 0;
u32 invoke_count = 0; u32 invoke_count = 0;
+120 -2
View File
@@ -24,6 +24,58 @@ static std::atomic<bool> g_wasm_epoch_running(false);
static String g_wasm_init_error; static String g_wasm_init_error;
static bool g_wasm_init_attempted = false; static bool g_wasm_init_attempted = false;
struct WasmEntryArtifactIdentity
{
dev_t device = 0;
ino_t inode = 0;
mode_t mode = 0;
off_t size = 0;
timespec modified = {};
timespec changed = {};
};
struct WasmEntryFreshnessState
{
std::chrono::steady_clock::time_point checked_at;
String source_generation;
WasmEntryArtifactIdentity wasm;
WasmEntryArtifactIdentity metadata;
WasmEntryArtifactIdentity setup_template;
};
static std::mutex g_wasm_entry_freshness_mutex;
static std::map<String, WasmEntryFreshnessState> g_wasm_entry_freshness;
static constexpr u64 WASM_ENTRY_FRESHNESS_CACHE_MAX = 4096;
static constexpr auto WASM_ENTRY_FRESHNESS_TTL = std::chrono::seconds(10);
static WasmEntryArtifactIdentity wasm_entry_artifact_identity(const struct stat& info)
{
return(WasmEntryArtifactIdentity{ info.st_dev, info.st_ino, info.st_mode, info.st_size, info.st_mtim, info.st_ctim });
}
static bool wasm_entry_artifact_identity_matches(const WasmEntryArtifactIdentity& expected, const struct stat& actual)
{
return(
expected.device == actual.st_dev && expected.inode == actual.st_ino && expected.mode == actual.st_mode && expected.size == actual.st_size &&
expected.modified.tv_sec == actual.st_mtim.tv_sec && expected.modified.tv_nsec == actual.st_mtim.tv_nsec &&
expected.changed.tv_sec == actual.st_ctim.tv_sec && expected.changed.tv_nsec == actual.st_ctim.tv_nsec
);
}
static bool wasm_entry_cache_allowed(Request* context)
{
if(!compiler_request_can_serve_stale_artifact(context))
return(false);
String method = to_upper(trim(context->params["REQUEST_METHOD"]));
return(method == "GET" || method == "HEAD" || method == "OPTIONS");
}
static void wasm_entry_freshness_forget(const String& entry_unit)
{
std::lock_guard<std::mutex> lock(g_wasm_entry_freshness_mutex);
g_wasm_entry_freshness.erase(entry_unit);
}
bool wasm_backend_configured(Request* context) bool wasm_backend_configured(Request* context)
{ {
return(context && context->server); return(context && context->server);
@@ -144,6 +196,41 @@ static bool wasm_artifact_exists(Request* context, const String& entry_unit)
return(false); return(false);
} }
context->stats.wasm_ready_artifact_stat_us += (u64)((time_precise() - phase_started) * 1000000.0); context->stats.wasm_ready_artifact_stat_us += (u64)((time_precise() - phase_started) * 1000000.0);
f64 freshness_started = time_precise();
bool cache_allowed = wasm_entry_cache_allowed(context);
String metadata_path = compiler_unit_bin_directory(context) + entry_unit + ".meta.txt";
String setup_template_path = path_join(context->server->config["COMPILER_SYS_PATH"], context->server->config["SETUP_TEMPLATE"]);
String source_generation;
struct stat metadata_st;
struct stat setup_template_st;
bool metadata_exists = false;
bool setup_template_exists = false;
auto now = std::chrono::steady_clock::now();
if(cache_allowed)
{
phase_started = time_precise();
source_generation = compiler_source_generation(context);
context->stats.wasm_ready_source_generation_us += (u64)((time_precise() - phase_started) * 1000000.0);
metadata_exists = stat(metadata_path.c_str(), &metadata_st) == 0 && S_ISREG(metadata_st.st_mode);
setup_template_exists = stat(setup_template_path.c_str(), &setup_template_st) == 0 && S_ISREG(setup_template_st.st_mode);
if(source_generation != "" && metadata_exists && setup_template_exists)
{
std::lock_guard<std::mutex> lock(g_wasm_entry_freshness_mutex);
auto cached = g_wasm_entry_freshness.find(entry_unit);
if(cached != g_wasm_entry_freshness.end() && now - cached->second.checked_at < WASM_ENTRY_FRESHNESS_TTL &&
cached->second.source_generation == source_generation &&
wasm_entry_artifact_identity_matches(cached->second.wasm, wasm_st) &&
wasm_entry_artifact_identity_matches(cached->second.metadata, metadata_st) &&
wasm_entry_artifact_identity_matches(cached->second.setup_template, setup_template_st))
{
context->stats.wasm_ready_freshness_cache_hit_count++;
context->stats.wasm_ready_freshness_us += (u64)((time_precise() - freshness_started) * 1000000.0);
return(true);
}
if(cached != g_wasm_entry_freshness.end())
g_wasm_entry_freshness.erase(cached);
}
}
// Require the artifact to satisfy the full compiler freshness check. Source // Require the artifact to satisfy the full compiler freshness check. Source
// mtime alone misses runtime/unit ABI changes, setup-template changes, and // mtime alone misses runtime/unit ABI changes, setup-template changes, and
// metadata mismatches, which can leave stale wasm with old imports. // metadata mismatches, which can leave stale wasm with old imports.
@@ -151,13 +238,44 @@ static bool wasm_artifact_exists(Request* context, const String& entry_unit)
phase_started = time_precise(); phase_started = time_precise();
if(compiler_unit_needs_recompile(context, entry_unit, &source_missing, false, true)) if(compiler_unit_needs_recompile(context, entry_unit, &source_missing, false, true))
{ {
context->stats.wasm_ready_freshness_us += (u64)((time_precise() - phase_started) * 1000000.0); u64 full_freshness_us = (u64)((time_precise() - phase_started) * 1000000.0);
context->stats.wasm_ready_freshness_us += (u64)((time_precise() - freshness_started) * 1000000.0);
context->stats.wasm_ready_freshness_full_check_us += full_freshness_us;
wasm_entry_freshness_forget(entry_unit);
compiler_prioritize_unit(context, entry_unit); compiler_prioritize_unit(context, entry_unit);
return(compiler_unit_can_serve_stale_artifact(context, entry_unit)); return(compiler_unit_can_serve_stale_artifact(context, entry_unit));
} }
context->stats.wasm_ready_freshness_us += (u64)((time_precise() - phase_started) * 1000000.0); u64 full_freshness_us = (u64)((time_precise() - phase_started) * 1000000.0);
context->stats.wasm_ready_freshness_full_check_us += full_freshness_us;
if(source_missing) if(source_missing)
{
context->stats.wasm_ready_freshness_us += (u64)((time_precise() - freshness_started) * 1000000.0);
wasm_entry_freshness_forget(entry_unit);
return(false); return(false);
}
if(cache_allowed && source_generation != "")
{
struct stat final_wasm_st;
struct stat final_metadata_st;
struct stat final_setup_template_st;
phase_started = time_precise();
String final_generation = compiler_source_generation(context);
context->stats.wasm_ready_source_generation_us += (u64)((time_precise() - phase_started) * 1000000.0);
if(final_generation == source_generation && stat(wasm_path.c_str(), &final_wasm_st) == 0 && S_ISREG(final_wasm_st.st_mode) &&
stat(metadata_path.c_str(), &final_metadata_st) == 0 && S_ISREG(final_metadata_st.st_mode) &&
stat(setup_template_path.c_str(), &final_setup_template_st) == 0 && S_ISREG(final_setup_template_st.st_mode))
{
std::lock_guard<std::mutex> lock(g_wasm_entry_freshness_mutex);
if(g_wasm_entry_freshness.size() >= WASM_ENTRY_FRESHNESS_CACHE_MAX)
g_wasm_entry_freshness.clear();
g_wasm_entry_freshness[entry_unit] = {
std::chrono::steady_clock::now(), final_generation,
wasm_entry_artifact_identity(final_wasm_st), wasm_entry_artifact_identity(final_metadata_st),
wasm_entry_artifact_identity(final_setup_template_st)
};
}
}
context->stats.wasm_ready_freshness_us += (u64)((time_precise() - freshness_started) * 1000000.0);
return(true); return(true);
} }
+13 -1
View File
@@ -1499,8 +1499,11 @@ public:
u64 ready_mutation_check_us = 0; u64 ready_mutation_check_us = 0;
u64 ready_artifact_stat_us = 0; u64 ready_artifact_stat_us = 0;
u64 ready_freshness_us = 0; u64 ready_freshness_us = 0;
u64 ready_source_generation_us = 0;
u64 ready_freshness_full_check_us = 0;
u64 ready_worker_us = 0; u64 ready_worker_us = 0;
u32 ready_check_count = 0; u32 ready_check_count = 0;
u32 ready_freshness_cache_hit_count = 0;
f64 workspace_wall_start = 0; f64 workspace_wall_start = 0;
f64 workspace_cpu_start = 0; f64 workspace_cpu_start = 0;
struct rusage thread_runtime_start = {}; struct rusage thread_runtime_start = {};
@@ -1608,7 +1611,8 @@ public:
void set_perf_snapshot(u64 worker_pid, u64 parent_pid, u64 request_count, void set_perf_snapshot(u64 worker_pid, u64 parent_pid, u64 request_count,
f64 time_init, f64 time_params, f64 time_input, f64 time_start, f64 time_init, f64 time_params, f64 time_input, f64 time_start,
u64 ready_normalize_us, u64 ready_mutation_check_us, u64 ready_artifact_stat_us, u64 ready_normalize_us, u64 ready_mutation_check_us, u64 ready_artifact_stat_us,
u64 ready_freshness_us, u64 ready_worker_us, u32 ready_check_count, u64 ready_freshness_us, u64 ready_source_generation_us, u64 ready_freshness_full_check_us,
u64 ready_worker_us, u32 ready_check_count, u32 ready_freshness_cache_hit_count,
f64 workspace_wall_start, f64 workspace_cpu_start) f64 workspace_wall_start, f64 workspace_cpu_start)
{ {
request_perf.worker_pid = worker_pid; request_perf.worker_pid = worker_pid;
@@ -1622,8 +1626,11 @@ public:
request_perf.ready_mutation_check_us = ready_mutation_check_us; request_perf.ready_mutation_check_us = ready_mutation_check_us;
request_perf.ready_artifact_stat_us = ready_artifact_stat_us; request_perf.ready_artifact_stat_us = ready_artifact_stat_us;
request_perf.ready_freshness_us = ready_freshness_us; request_perf.ready_freshness_us = ready_freshness_us;
request_perf.ready_source_generation_us = ready_source_generation_us;
request_perf.ready_freshness_full_check_us = ready_freshness_full_check_us;
request_perf.ready_worker_us = ready_worker_us; request_perf.ready_worker_us = ready_worker_us;
request_perf.ready_check_count = ready_check_count; request_perf.ready_check_count = ready_check_count;
request_perf.ready_freshness_cache_hit_count = ready_freshness_cache_hit_count;
request_perf.workspace_wall_start = workspace_wall_start; request_perf.workspace_wall_start = workspace_wall_start;
request_perf.workspace_cpu_start = workspace_cpu_start; request_perf.workspace_cpu_start = workspace_cpu_start;
request_perf.active = true; request_perf.active = true;
@@ -3042,8 +3049,11 @@ private:
response["ready_mutation_check_us"] = (f64)self->request_perf.ready_mutation_check_us; response["ready_mutation_check_us"] = (f64)self->request_perf.ready_mutation_check_us;
response["ready_artifact_stat_us"] = (f64)self->request_perf.ready_artifact_stat_us; response["ready_artifact_stat_us"] = (f64)self->request_perf.ready_artifact_stat_us;
response["ready_freshness_us"] = (f64)self->request_perf.ready_freshness_us; response["ready_freshness_us"] = (f64)self->request_perf.ready_freshness_us;
response["ready_source_generation_us"] = (f64)self->request_perf.ready_source_generation_us;
response["ready_freshness_full_check_us"] = (f64)self->request_perf.ready_freshness_full_check_us;
response["ready_worker_us"] = (f64)self->request_perf.ready_worker_us; response["ready_worker_us"] = (f64)self->request_perf.ready_worker_us;
response["ready_check_count"] = (f64)self->request_perf.ready_check_count; response["ready_check_count"] = (f64)self->request_perf.ready_check_count;
response["ready_freshness_cache_hit_count"] = (f64)self->request_perf.ready_freshness_cache_hit_count;
if(self->request_perf.time_start > 0 && self->request_perf.time_init > 0) if(self->request_perf.time_start > 0 && self->request_perf.time_init > 0)
response["accept_us"] = (f64)((self->request_perf.time_start - self->request_perf.time_init) * 1000000.0); response["accept_us"] = (f64)((self->request_perf.time_start - self->request_perf.time_init) * 1000000.0);
if(self->request_perf.time_params > 0 && self->request_perf.time_init > 0) if(self->request_perf.time_params > 0 && self->request_perf.time_init > 0)
@@ -4308,7 +4318,9 @@ inline WasmResponse wasm_worker_serve(WasmWorker& worker, const Request& request
request.stats.time_init, request.stats.time_params, request.stats.time_input, request.stats.time_start, request.stats.time_init, request.stats.time_params, request.stats.time_input, request.stats.time_start,
request.stats.wasm_ready_normalize_us, request.stats.wasm_ready_mutation_check_us, request.stats.wasm_ready_normalize_us, request.stats.wasm_ready_mutation_check_us,
request.stats.wasm_ready_artifact_stat_us, request.stats.wasm_ready_freshness_us, request.stats.wasm_ready_artifact_stat_us, request.stats.wasm_ready_freshness_us,
request.stats.wasm_ready_source_generation_us, request.stats.wasm_ready_freshness_full_check_us,
request.stats.wasm_ready_worker_us, request.stats.wasm_ready_check_count, request.stats.wasm_ready_worker_us, request.stats.wasm_ready_check_count,
request.stats.wasm_ready_freshness_cache_hit_count,
serve_started, cpu_started); serve_started, cpu_started);
workspace.request_perf.thread_runtime_start = thread_runtime_start; workspace.request_perf.thread_runtime_start = thread_runtime_start;
workspace.request_perf.thread_cpu_start = thread_cpu_start; workspace.request_perf.thread_cpu_start = thread_cpu_start;