a4d3b78cdb
First step toward an autoload-style lazy loader for the 499-file source tree (current cold load ~1s wall / 340ms user-time per CLI invocation, mostly spent sourcing files the command never calls). This commit only measures — no behaviour change unless LP_LOAD_TRACE=1. LP_LOAD_TRACE=1 instrumentation (scripts/source/loading/initilize_files.sh): Wraps each in the main file-list loop with EPOCHREALTIME before/after, writes `<elapsed_ms>\t<file_relpath>` to $LP_LOAD_TRACE_FILE (default /tmp/libreportal-load-trace.<pid>.log). Zero overhead when the env var is unset (one [[ test per file). libreportal debug load-trace [cmd...]: New `debug` CLI category. Spawns a child `libreportal <args>` (default 'help') with LP_LOAD_TRACE=1, then awk-aggregates the trace: wall vs cumulative source time, file count, top-15 hottest files. The diff between wall and cumulative-source = bash startup + dispatch + the command's own work. Used in the next phases to (a) validate that the lazy loader actually delivers the speedup we expect and (b) flag any single file that hogs disproportionate time (rare `heredoc | sed | base64` style work at source time would show up here as a >10ms entry). Signed-off-by: librelad <librelad@digitalangels.vip>
84 lines
2.9 KiB
Bash
84 lines
2.9 KiB
Bash
#!/bin/bash
|
|
|
|
cliHandleDebugCommands()
|
|
{
|
|
local action="$initial_command2"
|
|
|
|
case "$action" in
|
|
""|help)
|
|
cliShowDebugHelp
|
|
;;
|
|
load-trace)
|
|
cliDebugLoadTrace
|
|
;;
|
|
*)
|
|
isNotice "Invalid debug action: $action"
|
|
cliShowDebugHelp
|
|
;;
|
|
esac
|
|
}
|
|
|
|
# Run `libreportal <args>` with LP_LOAD_TRACE=1, then summarise the resulting
|
|
# trace file. We rebuild the args from initial_command3..7 (the CLI dispatcher
|
|
# doesn't pass $@ to category handlers — same constraint as the peer commands).
|
|
# A child shell invocation isolates the trace so it doesn't pollute the
|
|
# currently-loaded process.
|
|
cliDebugLoadTrace()
|
|
{
|
|
local args=()
|
|
local a
|
|
for a in "$initial_command3" "$initial_command4" "$initial_command5" "$initial_command6" "$initial_command7"; do
|
|
[[ -n "$a" ]] && args+=("$a")
|
|
done
|
|
[[ ${#args[@]} -eq 0 ]] && args=(help)
|
|
|
|
local trace_file
|
|
trace_file=$(mktemp -t libreportal-load-trace.XXXXXX.log)
|
|
|
|
isHeader "Load trace: libreportal ${args[*]}"
|
|
|
|
# Time the whole child invocation so we can compare 'wall' vs 'time spent
|
|
# in sourced files'. The diff = bash startup + dispatch + the command's
|
|
# own work (which for `help` is ~nothing, so wall ≈ load + bash startup).
|
|
local t0 t1 wall_ms
|
|
t0=$EPOCHREALTIME
|
|
LP_LOAD_TRACE=1 LP_LOAD_TRACE_FILE="$trace_file" \
|
|
libreportal "${args[@]}" >/dev/null 2>&1
|
|
t1=$EPOCHREALTIME
|
|
wall_ms=$(awk -v a="$t0" -v b="$t1" 'BEGIN{printf "%.1f", (b-a)*1000}')
|
|
|
|
if [[ ! -s "$trace_file" ]]; then
|
|
isError "Trace file empty — did the child invocation actually source files?"
|
|
rm -f "$trace_file"
|
|
return 1
|
|
fi
|
|
|
|
# Aggregate: total ms inside source, count, top-N hottest files. awk single
|
|
# pass — no need for sort | head | wc dance.
|
|
awk -v wall="$wall_ms" -v file="$trace_file" '
|
|
{ ms=$1; sub(/^[^\t]*\t/,""); path=$0
|
|
total+=ms; n++
|
|
if (ms > 0.1) { top_ms[n]=ms; top_path[n]=path }
|
|
}
|
|
END {
|
|
printf " Wall time (child invocation): %s ms\n", wall
|
|
printf " Files sourced: %d\n", n
|
|
printf " Cumulative source time: %.1f ms\n", total
|
|
if (n>0) printf " Average per file: %.3f ms\n", total/n
|
|
printf "\n Top 15 hottest files (>0.1 ms):\n"
|
|
# Quick sort by ms descending (small N, n^2 is fine).
|
|
for (i=1;i<=n;i++) for (j=i+1;j<=n;j++)
|
|
if (top_ms[j]>top_ms[i]) {
|
|
t=top_ms[i]; top_ms[i]=top_ms[j]; top_ms[j]=t
|
|
t=top_path[i]; top_path[i]=top_path[j]; top_path[j]=t
|
|
}
|
|
shown=0
|
|
for (i=1;i<=n && shown<15;i++) if (top_ms[i]>0) {
|
|
printf " %8.3f ms %s\n", top_ms[i], top_path[i]
|
|
shown++
|
|
}
|
|
printf "\n Full trace at: %s\n", file
|
|
}
|
|
' "$trace_file"
|
|
}
|