From 0bcf9a676ef7aaecf1f9be25a3791d4596b027c9 Mon Sep 17 00:00:00 2001 From: udo Date: Tue, 14 Jul 2026 22:15:13 +0000 Subject: [PATCH] flush runtime diagnostics promptly --- docs/wasm-runtime-architecture.md | 5 ++++ scripts/run_cli_tests.sh | 1 + scripts/test_log_timeliness.sh | 48 +++++++++++++++++++++++++++++++ src/linux_fastcgi.cpp | 4 +++ 4 files changed, 58 insertions(+) create mode 100755 scripts/test_log_timeliness.sh diff --git a/docs/wasm-runtime-architecture.md b/docs/wasm-runtime-architecture.md index 6f0a723..06c6ea4 100644 --- a/docs/wasm-runtime-architecture.md +++ b/docs/wasm-runtime-architecture.md @@ -402,6 +402,11 @@ header free-functions are `inline`. The wasm backend exposes only declarations independently enforces the same canonical identity, and persisted failures are reused only when their recorded source path matches the current request. +- **Log timeliness**: the base process line-buffers stdout before forking + workers, the proactive compiler, and the WebSocket broker. This keeps each + newline-terminated diagnostic attached to its actual journal time instead of + releasing an old block-buffered failure during unrelated later traffic. + - **WebSocket end-to-end**: a headless client performs a raw WS handshake to `:HTTP_PORT` with path `/site/tests/websockets.ws.uce` (self-resolving `SCRIPT_FILENAME`) and asserts the `hello-ack` frame — exercising the full diff --git a/scripts/run_cli_tests.sh b/scripts/run_cli_tests.sh index 309173f..b82b23c 100755 --- a/scripts/run_cli_tests.sh +++ b/scripts/run_cli_tests.sh @@ -69,4 +69,5 @@ if [[ "$action" == "run" ]]; then scripts/test_dependency_invalidation.sh scripts/test_cold_component_deadline.sh scripts/test_password_hashing.sh + scripts/test_log_timeliness.sh fi diff --git a/scripts/test_log_timeliness.sh b/scripts/test_log_timeliness.sh new file mode 100755 index 0000000..d5e2ee2 --- /dev/null +++ b/scripts/test_log_timeliness.sh @@ -0,0 +1,48 @@ +#!/usr/bin/env bash +set -euo pipefail +cd "$(dirname "$0")/.." + +test_name="log-timeliness-test-$$" +site_directory="${UCE_TEST_SITE_DIRECTORY:-site}" +if [[ -z "${UCE_TEST_SITE_DIRECTORY:-}" && -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) + if [[ -n "${configured_site_directory:-}" ]]; then + site_directory="$configured_site_directory" + fi +fi +source_dir="$site_directory/$test_name" +bin_directory="${BIN_DIRECTORY:-}" +if [[ -z "$bin_directory" && -r /etc/uce/settings.cfg ]]; then + bin_directory=$(awk -F= '/^[[:space:]]*BIN_DIRECTORY[[:space:]]*=/ {gsub(/^[[:space:]]+|[[:space:]]+$/, "", $2); print $2; exit}' /etc/uce/settings.cfg) +fi +bin_directory="${bin_directory:-/tmp/uce/work}" +cache_dir="" + +cleanup() { + rm -rf "$source_dir" + if [[ -n "$cache_dir" ]]; then + rm -rf "$cache_dir" + fi +} +trap cleanup EXIT +mkdir -p "$source_dir" +cache_dir="$bin_directory$(realpath "$source_dir")" + +printf '%s\n' 'CLI(Request& context) { deliberate_log_timeliness_compile_failure }' >"$source_dir/probe.uce" +rm -rf "$cache_dir" +started_at=$(date '+%Y-%m-%d %H:%M:%S') + +set +e +scripts/uce-cli "/$test_name/probe.uce" >/dev/null 2>&1 +set -e + +for _ in $(seq 1 20); do + if journalctl -u uce --since "$started_at" --no-pager | grep -Fq "$test_name/probe.uce"; then + echo "log timeliness passed" + exit 0 + fi + sleep 0.1 +done + +echo "compile diagnostic was not journaled promptly: $test_name/probe.uce" >&2 +exit 1 diff --git a/src/linux_fastcgi.cpp b/src/linux_fastcgi.cpp index 5133873..9e98eb3 100644 --- a/src/linux_fastcgi.cpp +++ b/src/linux_fastcgi.cpp @@ -1467,6 +1467,10 @@ void init_base_process() int main(int argc, char** argv) { + // systemd connects stdout to a pipe, which otherwise block-buffers child + // diagnostics and assigns stale failures a misleading later journal time. + setvbuf(stdout, 0, _IOLBF, 0); + setvbuf(stderr, 0, _IONBF, 0); // Warm up libgcc's backtrace state so the first in-handler backtrace() // after a fault does not allocate. backtrace(request_fault_frames, 4);