diff --git a/spruce/scripts/archiveUnpacker.sh b/spruce/scripts/archiveUnpacker.sh index 942bc1b6a..f8f1dd31a 100644 --- a/spruce/scripts/archiveUnpacker.sh +++ b/spruce/scripts/archiveUnpacker.sh @@ -1,109 +1,375 @@ #!/bin/sh THEME_DIR="/mnt/SDCARD/Themes" -RA_THEME_DIR="/mnt/SDCARD/RetroArch/.retroarch/assets" ARCHIVE_DIR="/mnt/SDCARD/spruce/archives" ICON="/mnt/SDCARD/spruce/imgs/iconfresh.png" +STATE_FILE="/mnt/SDCARD/Saves/spruce/unpacker_state" +PRECMD_PID_FILE="/mnt/SDCARD/spruce/flags/unpacker_precmd.pid" +HANDOFF_FLAG="unpacker_handoff_pre_cmd" +FIRSTBOOT_PACKAGE_PHASE_FLAG="firstboot_packages_extracting" +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" . /mnt/SDCARD/spruce/scripts/helperFunctions.sh -# This is a service to unpack archives that a preformatted to land in the right place. -# Since some files need to be available before the menu is displayed, we need to unpack them before the menu is displayed so that's one mode. -# The other mode is to unpack archives needed before the command_to_run, this is used for the preCmd folder. +# This is a service to unpack archives that are preformatted to land in the right place. +# Since some files need to be available before the menu is displayed, we need to unpack them before +# the menu is displayed so that's one mode. +# The other mode is to unpack archives needed before the command_to_run, this is used for preCmd. -# This can be called with a "pre_cmd" argument to run a check and unpack over the preCmd folder only. -# Typically you'd use that for any unpacking process since we don't want extraction to happen in the background. -# It's rather resource heavy and we don't want leave it running in the background. +# This can be called with a "pre_cmd" argument to run over preCmd only. +# On firstboot this now runs fully in the foreground; on non-firstboot paths, +# pre_cmd may still hand off to a background worker when safe. -# If a silentUnpacker flag is present another script is running and we don't want to run this one. -if flag_check "silentUnpacker"; then - log_message "Unpacker: Another silent unpacker is running, exiting" -v - exit 0 -fi +SKIP_SILENT_CLEANUP=0 +UNPACK_HAD_FAILURE=0 +HANDOFF_BACKGROUND=0 +RUN_MODE="all" +SILENT_STATE="0" +FORCE_FOREGROUND_PRECMD="${UNPACKER_FORCE_FOREGROUND_PRECMD:-0}" +TRACE_FINAL_STATE="FINALIZED" +TRACE_FINAL_REASON="normal-exit" +TRACE_FINALIZED=0 -log_message "Unpacker: Script started" +emit_archive_trace_finalize() { + [ "$TRACE_FINALIZED" = "1" ] && return 0 + "$SYSTEM_EMIT" process-finalize archiveUnpacker "archiveUnpacker.sh" "$TRACE_FINAL_STATE" "reason=$TRACE_FINAL_REASON run_mode=$RUN_MODE silent_state=$SILENT_STATE" || true + TRACE_FINALIZED=1 +} + +write_unpack_state() { + state_value="$1" + reason_value="$2" + pid_value="$3" + tmp_state="${STATE_FILE}.tmp.$$" + + mkdir -p "$(dirname "$STATE_FILE")" 2>/dev/null + { + printf 'state=%s\n' "$state_value" + printf 'run_mode=%s\n' "$RUN_MODE" + printf 'pid=%s\n' "${pid_value:-}" + printf 'updated_at=%s\n' "$(date '+%Y-%m-%d %H:%M:%S')" + printf 'reason=%s\n' "${reason_value:-}" + } > "$tmp_state" + mv -f "$tmp_state" "$STATE_FILE" +} + +set_trace_outcome() { + TRACE_FINAL_STATE="$1" + TRACE_FINAL_REASON="$2" +} + +exit_with_state() { + state_value="$1" + state_reason="$2" + trace_state="$3" + trace_reason="$4" + exit_code="${5:-0}" + log_line_1="$6" + log_line_2="$7" + pid_value="${8:-}" + + write_unpack_state "$state_value" "$state_reason" "$pid_value" + set_trace_outcome "$trace_state" "$trace_reason" + [ -n "$log_line_1" ] && log_message "$log_line_1" + [ -n "$log_line_2" ] && log_message "$log_line_2" + exit "$exit_code" +} + +exit_with_trace_only() { + trace_state="$1" + trace_reason="$2" + exit_code="${3:-0}" + log_line="$4" + + set_trace_outcome "$trace_state" "$trace_reason" + [ -n "$log_line" ] && log_message "$log_line" + exit "$exit_code" +} + +queue_has_archive() { + dir="$1" + [ -n "$(find "$dir" -maxdepth 1 -name '*.7z' | head -n 1)" ] +} + +queue_empty_for_mode() { + if [ "$RUN_MODE" = "themes_only" ]; then + ! queue_has_archive "$THEME_DIR" + return + fi + + if [ "$RUN_MODE" = "pre_cmd" ]; then + ! queue_has_archive "$ARCHIVE_DIR/preCmd" + return + fi + + ! queue_has_archive "$THEME_DIR" && + ! queue_has_archive "$ARCHIVE_DIR/preMenu" && + ! queue_has_archive "$ARCHIVE_DIR/preCmd" +} cleanup() { + if [ "$RUN_MODE" = "pre_cmd" ]; then + rm -f "$PRECMD_PID_FILE" + fi + + if [ "$SKIP_SILENT_CLEANUP" = "1" ]; then + "$SYSTEM_EMIT" process archiveUnpacker "CLEANUP_SKIP_SILENT_LOCK_REMOVE" "archiveUnpacker.sh/cleanup" "handoff owns silentUnpacker lock" || true + return + fi + + "$SYSTEM_EMIT" process archiveUnpacker "CLEANUP_REMOVE_SILENT_LOCK" "archiveUnpacker.sh/cleanup" "removing silentUnpacker lock" || true flag_remove "silentUnpacker" } +archive_exit_handler() { + cleanup + emit_archive_trace_finalize +} + +parse_startup_args() { + arg1="$1" + arg2="$2" + + if [ "$arg1" = "--silent" ]; then + flag_add "silentUnpacker" --tmp + SILENT_STATE="1" + [ -n "$arg2" ] && RUN_MODE="$arg2" + elif [ -n "$arg1" ]; then + RUN_MODE="$arg1" + fi +} + +wait_for_firstboot_package_phase() { + wait_loops=0 + if flag_check "$FIRSTBOOT_PACKAGE_PHASE_FLAG"; then + "$SYSTEM_EMIT" process archiveUnpacker "WAIT_FIRSTBOOT_PACKAGE_PHASE_BEGIN" "archiveUnpacker.sh/startup" "flag=$FIRSTBOOT_PACKAGE_PHASE_FLAG" || true + while flag_check "$FIRSTBOOT_PACKAGE_PHASE_FLAG"; do + wait_loops=$((wait_loops + 1)) + if [ $((wait_loops % 50)) -eq 0 ]; then + "$SYSTEM_EMIT" process archiveUnpacker "WAIT_FIRSTBOOT_PACKAGE_PHASE_LOOP" "archiveUnpacker.sh/startup" "flag=$FIRSTBOOT_PACKAGE_PHASE_FLAG loops=$wait_loops" || true + fi + sleep 0.1 + done + "$SYSTEM_EMIT" process archiveUnpacker "WAIT_FIRSTBOOT_PACKAGE_PHASE_END" "archiveUnpacker.sh/startup" "flag=$FIRSTBOOT_PACKAGE_PHASE_FLAG loops=$wait_loops" || true + fi +} + +"$SYSTEM_EMIT" process-init archiveUnpacker "archiveUnpacker.sh" "argv1=${1:-} argv2=${2:-}" || true + +# Guard against overlapping unpack workers. +# A --silent pre_cmd worker is allowed to enter only when an explicit parent handoff flag exists. +if flag_check "silentUnpacker"; then + if [ "$1" = "--silent" ] && [ "$2" = "pre_cmd" ] && flag_check "$HANDOFF_FLAG"; then + flag_remove "$HANDOFF_FLAG" + "$SYSTEM_EMIT" process archiveUnpacker "HANDOFF_ACCEPTED" "archiveUnpacker.sh/startup-guard" "accepted silent pre_cmd handoff" || true + else + log_message "Unpacker: Another silent unpacker is running, exiting" -v + "$SYSTEM_EMIT" process archiveUnpacker "EARLY_EXIT_SILENT_LOCK_EXISTS" "archiveUnpacker.sh/startup-guard" "silentUnpacker lock exists" || true + TRACE_FINAL_STATE="SKIPPED_LOCK" + TRACE_FINAL_REASON="existing-silentUnpacker-lock" + emit_archive_trace_finalize + exit 0 + fi +fi + +log_message "Unpacker: Script started" + # Set trap for script exit -trap cleanup EXIT +trap archive_exit_handler EXIT # Process command line arguments -RUN_MODE="all" -if [ "$1" = "--silent" ]; then - flag_add "silentUnpacker" --tmp - [ -n "$2" ] && RUN_MODE="$2" -elif [ -n "$1" ]; then - RUN_MODE="$1" -fi +parse_startup_args "${1:-}" "${2:-}" +wait_for_firstboot_package_phase +if flag_check "silentUnpacker"; then + SILENT_STATE="1" +fi +"$SYSTEM_EMIT" process archiveUnpacker "STARTUP_MODE" "archiveUnpacker.sh/startup" "run_mode=$RUN_MODE silent_state=$SILENT_STATE" || true +write_unpack_state "running" "startup" "" # Function to display text if not in silent mode display_if_not_silent() { - flag_check "silentUnpacker" || start_pyui_message_writer - flag_check "silentUnpacker" || display_image_and_text "$ICON" 35 25 "$archive_name archive detected. Unpacking.........." 75 + section_label="$1" + detail_line="$2" + hold_seconds="${3:-0}" + + if flag_check "silentUnpacker"; then + return 0 + fi + + start_pyui_message_writer + "$SYSTEM_EMIT" process archiveUnpacker "UI_NOTIFY_ARCHIVE" "archiveUnpacker.sh/display_if_not_silent" "section=${section_label:-unknown} detail=${detail_line:-unknown}" || true + if [ "${SPRUCE_FIRSTBOOT_UI:-0}" = "1" ]; then + display_image_and_text "$ICON" 35 25 "Sprucing up your device...\nUnpacking ${section_label}\n${detail_line}" 75 + else + display_image_and_text "$ICON" 35 25 "Unpacking ${section_label}\n${detail_line}" 75 + fi + if [ "$hold_seconds" -gt 0 ]; then + sleep "$hold_seconds" + fi } # Function to unpack archives from a specified directory unpack_archives() { - local dir="$1" - local flag_name="$2" + dir="$1" + flag_name="$2" + section_label="$3" + found_count=0 + success_count=0 + fail_count=0 + skip_count=0 + section_delay_applied=0 + + [ -z "$section_label" ] && section_label="archives" [ -n "$flag_name" ] && flag_add "$flag_name" --tmp + "$SYSTEM_EMIT" process archiveUnpacker "FLAG_SET" "archiveUnpacker.sh/unpack_archives" "flag=${flag_name:-none} dir=$dir section=$section_label" || true + "$SYSTEM_EMIT" process archiveUnpacker "BEGIN_DIR" "archiveUnpacker.sh/unpack_archives" "dir=$dir" || true for archive in "$dir"/*.7z; do if [ -f "$archive" ]; then + found_count=$((found_count + 1)) archive_name=$(basename "$archive" .7z) - display_if_not_silent + "$SYSTEM_EMIT" process archiveUnpacker "ARCHIVE_CANDIDATE" "archiveUnpacker.sh/unpack_archives" "archive=$archive_name.7z dir=$dir" || true + section_hold=0 + if [ "$section_delay_applied" -eq 0 ]; then + section_hold=2 + section_delay_applied=1 + fi + display_if_not_silent "$section_label" "$archive_name.7z" "$section_hold" if 7zr l "$archive" | grep -q "/mnt/SDCARD/"; then if 7zr x -aoa "$archive" -o/; then rm -f "$archive" + success_count=$((success_count + 1)) log_message "Unpacker: Unpacked and removed: $archive_name.7z" else + fail_count=$((fail_count + 1)) + UNPACK_HAD_FAILURE=1 log_message "Unpacker: Failed to unpack: $archive_name.7z" fi else + skip_count=$((skip_count + 1)) log_message "Unpacker: Skipped unpacking: $archive_name.7z (incorrect folder structure)" fi fi done + "$SYSTEM_EMIT" process archiveUnpacker "SUMMARY" "archiveUnpacker.sh/unpack_archives" "dir=$dir found=$found_count success=$success_count failed=$fail_count skipped=$skip_count" || true [ -n "$flag_name" ] && flag_remove "$flag_name" + "$SYSTEM_EMIT" process archiveUnpacker "FLAG_CLEARED" "archiveUnpacker.sh/unpack_archives" "flag=${flag_name:-none} dir=$dir" || true } # Quick check for .7z files in relevant directories if [ "$RUN_MODE" = "all" ] && - [ -z "$(find "$ARCHIVE_DIR/preCmd" -maxdepth 1 -name '*.7z' | head -n 1)" ] && - [ -z "$(find "$ARCHIVE_DIR/preMenu" -maxdepth 1 -name '*.7z' | head -n 1)" ] && - [ -z "$(find "$THEME_DIR" -maxdepth 1 -name '*.7z' | head -n 1)" ] && - [ -z "$(find "$RA_THEME_DIR" -maxdepth 1 -name '*.7z' | head -n 1)" ]; then - log_message "Unpacker: No .7z files found to unpack. Exiting." - exit 0 + ! queue_has_archive "$ARCHIVE_DIR/preCmd" && + ! queue_has_archive "$ARCHIVE_DIR/preMenu" && + ! queue_has_archive "$THEME_DIR"; then + "$SYSTEM_EMIT" process archiveUnpacker "QUEUE_EMPTY_FAST_PATH" "archiveUnpacker.sh/startup" "no archives in themes/preMenu/preCmd" || true + exit_with_state \ + "complete" "queue-empty" \ + "COMPLETE" "queue-empty-fast-path" \ + "0" \ + "Unpacker: No .7z files found to unpack. Exiting." \ + "Unpacker: Finished running" +fi + +if [ "$RUN_MODE" = "themes_only" ] && + ! queue_has_archive "$THEME_DIR"; then + "$SYSTEM_EMIT" process archiveUnpacker "QUEUE_EMPTY_THEMES_FAST_PATH" "archiveUnpacker.sh/startup" "no archives in themes" || true + exit_with_state \ + "complete" "queue-empty-themes" \ + "COMPLETE" "queue-empty-themes-fast-path" \ + "0" \ + "Unpacker: No theme .7z files found to unpack. Exiting." \ + "Unpacker: Finished running" fi log_message "Unpacker: Starting theme and archive unpacking process" -# Process archives based on run mode -case "$RUN_MODE" in -"all") - unpack_archives "$THEME_DIR" - unpack_archives "$ARCHIVE_DIR/preMenu" "pre_menu_unpacking" - if flag_check "save_active"; then - unpack_archives "$ARCHIVE_DIR/preCmd" "pre_cmd_unpacking" +run_mode_all() { + unpack_archives "$THEME_DIR" "" "Themes" + unpack_archives "$ARCHIVE_DIR/preMenu" "pre_menu_unpacking" "Pre-menu content" + if [ "$FORCE_FOREGROUND_PRECMD" = "1" ] || flag_check "save_active"; then + if [ "$FORCE_FOREGROUND_PRECMD" = "1" ]; then + "$SYSTEM_EMIT" process archiveUnpacker "PRECMD_FOREGROUND_FORCED" "archiveUnpacker.sh/run_mode_all" "forced foreground pre_cmd in sequential firstboot" || true + else + "$SYSTEM_EMIT" process archiveUnpacker "PRECMD_FOREGROUND_SAVE_ACTIVE" "archiveUnpacker.sh/run_mode_all" "save_active=1" || true + fi + unpack_archives "$ARCHIVE_DIR/preCmd" "pre_cmd_unpacking" "System content" else - flag_add "silentUnpacker" --tmp - unpack_archives "$ARCHIVE_DIR/preCmd" "pre_cmd_unpacking" & + "$SYSTEM_EMIT" process archiveUnpacker "PRECMD_HANDOFF_BACKGROUND" "archiveUnpacker.sh/run_mode_all" "save_active=0" || true + flag_add "$HANDOFF_FLAG" --tmp + /mnt/SDCARD/spruce/scripts/archiveUnpacker.sh --silent pre_cmd & + handoff_pid="$!" + HANDOFF_BACKGROUND=1 + echo "$handoff_pid" > "$PRECMD_PID_FILE" + write_unpack_state "running" "handoff-pre_cmd" "$handoff_pid" + SKIP_SILENT_CLEANUP=1 + "$SYSTEM_EMIT" process archiveUnpacker "PRECMD_HANDOFF_SPAWNED" "archiveUnpacker.sh/run_mode_all" "pid=$handoff_pid" || true fi - ;; -"pre_cmd") - unpack_archives "$ARCHIVE_DIR/preCmd" "pre_cmd_unpacking" - ;; -*) - log_message "Unpacker: Invalid run mode specified" - exit 1 - ;; -esac - -log_message "Unpacker: Finished running" +} + +run_mode_pre_cmd() { + "$SYSTEM_EMIT" process archiveUnpacker "PRECMD_MODE_FOREGROUND" "archiveUnpacker.sh/run_mode_pre_cmd" "foreground pre_cmd run" || true + echo "$$" > "$PRECMD_PID_FILE" + write_unpack_state "running" "pre_cmd-active" "$$" + unpack_archives "$ARCHIVE_DIR/preCmd" "pre_cmd_unpacking" "System content" +} + +run_mode_themes_only() { + "$SYSTEM_EMIT" process archiveUnpacker "THEMES_ONLY_MODE_FOREGROUND" "archiveUnpacker.sh/run_mode_themes_only" "foreground themes-only run" || true + write_unpack_state "running" "themes-only-active" "$$" + unpack_archives "$THEME_DIR" "" "Themes" +} + +dispatch_run_mode() { + case "$RUN_MODE" in + "all") + run_mode_all + ;; + "themes_only") + run_mode_themes_only + ;; + "pre_cmd") + run_mode_pre_cmd + ;; + *) + exit_with_state \ + "failed_resumable" "invalid-run-mode" \ + "FAILED" "invalid-run-mode" \ + "1" \ + "Unpacker: Invalid run mode specified" + ;; + esac +} + +dispatch_run_mode + +if [ "$HANDOFF_BACKGROUND" = "1" ]; then + exit_with_trace_only \ + "HANDOFF_BACKGROUND" "pre_cmd-background-handoff" \ + "0" \ + "Unpacker: Foreground phases finished; pre_cmd handed off to background worker." +fi + +if [ "$UNPACK_HAD_FAILURE" -ne 0 ]; then + exit_with_state \ + "failed_resumable" "archive-extract-failure" \ + "FAILED" "archive-extract-failure" \ + "1" \ + "Unpacker: Incomplete due to extraction failures; resumable state persisted." +fi + +if queue_empty_for_mode; then + exit_with_state \ + "complete" "queue-empty" \ + "COMPLETE" "queue-empty" \ + "0" \ + "Unpacker: Finished running" +else + exit_with_state \ + "failed_resumable" "queue-not-empty" \ + "FAILED" "queue-not-empty" \ + "1" \ + "Unpacker: Incomplete queue detected; resumable state persisted." +fi diff --git a/spruce/scripts/firstboot.sh b/spruce/scripts/firstboot.sh index 437c13367..dbda3da82 100644 --- a/spruce/scripts/firstboot.sh +++ b/spruce/scripts/firstboot.sh @@ -2,22 +2,65 @@ . /mnt/SDCARD/spruce/scripts/helperFunctions.sh . /mnt/SDCARD/spruce/scripts/network/sshFunctions.sh +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" +FIRSTBOOT_PACKAGE_PHASE_FLAG="firstboot_packages_extracting" start_pyui_message_writer flag_remove "first_boot_$PLATFORM" log_message "Starting firstboot script on $PLATFORM" +"$SYSTEM_EMIT" process firstboot "STARTED" "firstboot.sh/startup" "platform=$PLATFORM" || true WIKI_ICON="/mnt/SDCARD/spruce/imgs/book.png" -HAPPY_ICON="/mnt/SDCARD/spruce/imgs/smile.png" -UNPACKING_ICON="/mnt/SDCARD/spruce/imgs/refreshing.png" SPRUCE_LOGO="/mnt/SDCARD/spruce/imgs/tree_sm_close_crop.png" SPRUCE_VERSION="$(cat "/mnt/SDCARD/spruce/spruce")" SPLORE_CART="/mnt/SDCARD/Roms/PICO8/-=☆ Launch Splore ☆=-.splore" +FIRSTBOOT_PRE_EXTRACT_SCREENS="$SPRUCE_LOGO|Installing spruce $SPRUCE_VERSION|5" +FIRSTBOOT_POST_EXTRACT_SCREENS="$WIKI_ICON|Check out the spruce wiki on our GitHub page for tips and FAQs!|5" +FIRSTBOOT_FINAL_STATE="COMPLETE" +FIRSTBOOT_FINAL_REASON="normal-exit" +FIRSTBOOT_FINALIZED=0 + +firstboot_trace_finalize() { + [ "$FIRSTBOOT_FINALIZED" = "1" ] && return 0 + "$SYSTEM_EMIT" process-finalize firstboot "firstboot.sh" "$FIRSTBOOT_FINAL_STATE" "reason=$FIRSTBOOT_FINAL_REASON platform=$PLATFORM" || true + FIRSTBOOT_FINALIZED=1 +} + +cleanup_firstboot() { + flag_remove "$FIRSTBOOT_PACKAGE_PHASE_FLAG" + firstboot_trace_finalize +} +trap cleanup_firstboot EXIT + +"$SYSTEM_EMIT" process-init firstboot "firstboot.sh" "platform=$PLATFORM" || true + +show_firstboot_screen() { + img="$1" + text="$2" + duration="${3:-5}" + if [ "${SPRUCE_FIRSTBOOT_UI:-0}" = "1" ]; then + case "$text" in + "Check out the spruce wiki on our GitHub page for tips and FAQs!"*) ;; + *) text="Sprucing up your device...\n${text}" ;; + esac + fi + + display_image_and_text "$img" 35 25 "$text" 75 + sleep "$duration" +} + +run_firstboot_screen_table() { + table_rows="$1" + [ -n "$table_rows" ] || return 0 + printf '%s\n' "$table_rows" | while IFS='|' read -r img text duration; do + [ -n "$img" ] || continue + show_firstboot_screen "$img" "$text" "${duration:-5}" + done +} -display_image_and_text "$SPRUCE_LOGO" 35 25 "Installing spruce $SPRUCE_VERSION" 75 -sleep 5 # make sure installing spruce logo stays up longer; gives more time for XMB to unpack too +run_firstboot_screen_table "$FIRSTBOOT_PRE_EXTRACT_SCREENS" SSH_SERVICE_NAME=$(get_ssh_service_name) if [ "$SSH_SERVICE_NAME" = "dropbearmulti" ]; then @@ -25,12 +68,15 @@ if [ "$SSH_SERVICE_NAME" = "dropbearmulti" ]; then dropbear_generate_keys & fi +flag_add "$FIRSTBOOT_PACKAGE_PHASE_FLAG" --tmp +"$SYSTEM_EMIT" process firstboot "PACKAGE_PHASE_BEGIN" "firstboot.sh/package-phase" "flag=$FIRSTBOOT_PACKAGE_PHASE_FLAG" || true + if [ "$DEVICE_SUPPORTS_PORTMASTER" = "true" ]; then mkdir -p /mnt/SDCARD/Persistent/ if [ ! -d "/mnt/SDCARD/Persistent/portmaster" ] ; then - extract_7z_with_progress /mnt/SDCARD/App/PortMaster/portmaster.7z /mnt/SDCARD/Persistent/ /mnt/SDCARD/Saves/spruce/portmaster_extract.log "Sprucing up your device" + extract_7z_with_progress /mnt/SDCARD/App/PortMaster/portmaster.7z /mnt/SDCARD/Persistent/ /mnt/SDCARD/Saves/spruce/portmaster_extract.log "PortMaster" else - display_image_and_text "$SPRUCE_LOGO" 35 25 "Sprucing up your device" 75 + run_firstboot_screen_table "$SPRUCE_LOGO|Unpacking PortMaster\nAlready installed|2" fi rm -f /mnt/SDCARD/App/PortMaster/portmaster.7z @@ -43,23 +89,22 @@ if [ "$PLATFORM_ARCHITECTURE" != "armhf" ]; then SCUMMVM_DIR="/mnt/SDCARD/Emu/SCUMMVM" for SCUMMVM_7Z in "$SCUMMVM_DIR"/scummvm_*.7z; do [ -f "$SCUMMVM_7Z" ] || continue - extract_7z_with_progress "$SCUMMVM_7Z" "$SCUMMVM_DIR" /mnt/SDCARD/Saves/spruce/scummvm_extract.log "Installing ScummVM" + extract_7z_with_progress "$SCUMMVM_7Z" "$SCUMMVM_DIR" /mnt/SDCARD/Saves/spruce/scummvm_extract.log "ScummVM" rm -f "$SCUMMVM_7Z" done fi -display_image_and_text "$WIKI_ICON" 35 25 "Check out the spruce wiki on our GitHub page for tips and FAQs!" 75 -sleep 5 +flag_remove "$FIRSTBOOT_PACKAGE_PHASE_FLAG" +"$SYSTEM_EMIT" process firstboot "PACKAGE_PHASE_END" "firstboot.sh/package-phase" "flag=$FIRSTBOOT_PACKAGE_PHASE_FLAG" || true -perform_fw_check +log_message "Firstboot: Running themes-only archive extraction before final transition screens" +"$SYSTEM_EMIT" process archiveUnpacker "FIRSTBOOT_THEMES_ONLY_LAUNCH" "firstboot.sh/themes-only" "run_mode=themes_only" || true +SPRUCE_FIRSTBOOT_UI="${SPRUCE_FIRSTBOOT_UI:-0}" /mnt/SDCARD/spruce/scripts/archiveUnpacker.sh themes_only +"$SYSTEM_EMIT" process archiveUnpacker "FIRSTBOOT_THEMES_ONLY_RESULT" "firstboot.sh/themes-only" "run_mode=themes_only completed" || true -if flag_check "pre_menu_unpacking"; then - display_image_and_text "$UNPACKING_ICON" 35 25 "Finishing up unpacking themes and files.........." 75 - flag_remove "silentUnpacker" - while flag_check "pre_menu_unpacking"; do - sleep 0.2 - done -fi +run_firstboot_screen_table "$FIRSTBOOT_POST_EXTRACT_SCREENS" + +perform_fw_check # create splore launcher if it doesn't already exist if [ ! -f "$SPLORE_CART" ]; then @@ -69,8 +114,5 @@ else fi "$(get_python_path)" -O -m compileall /mnt/SDCARD/App/PyUI/main-ui/ - -display_image_and_text "$HAPPY_ICON" 35 25 "Happy gaming.........." 75 -sleep 5 - log_message "Finished firstboot script" +"$SYSTEM_EMIT" process firstboot "COMPLETED" "firstboot.sh/shutdown" "platform=$PLATFORM" || true diff --git a/spruce/scripts/helperFunctions.sh b/spruce/scripts/helperFunctions.sh index b1ee1b5a8..348b6b229 100644 --- a/spruce/scripts/helperFunctions.sh +++ b/spruce/scripts/helperFunctions.sh @@ -17,6 +17,7 @@ export FLAGS_DIR="/mnt/SDCARD/spruce/flags" export MESSAGES_FILE="/var/log/messages" POWER_OFF_SCRIPT="/mnt/SDCARD/spruce/scripts/save_poweroff.sh" +export SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" # Export for enabling SSL support in CURL export SSL_CERT_FILE=/mnt/SDCARD/spruce/etc/ca-certificates.crt @@ -174,12 +175,21 @@ dim_screen() { finish_unpacking() { flag="$1" if flag_check "$flag"; then + "$SYSTEM_EMIT" process archiveUnpacker "FINISH_UNPACKING_ENTER" "helperFunctions.sh/finish_unpacking" "flag=$flag" || true start_pyui_message_writer log_and_display_message "Finishing up unpacking archives.........." - flag_remove "silentUnpacker" + "$SYSTEM_EMIT" process archiveUnpacker "FINISH_UNPACKING_WAIT_PRESERVE_SILENT" "helperFunctions.sh/finish_unpacking" "flag=$flag" || true + wait_loops=0 while [ -f "$FLAGS_DIR/$flag.lock" ]; do + wait_loops=$((wait_loops + 1)) + if [ $((wait_loops % 50)) -eq 0 ]; then + "$SYSTEM_EMIT" process archiveUnpacker "FINISH_UNPACKING_WAIT_LOOP" "helperFunctions.sh/finish_unpacking" "flag=$flag loops=$wait_loops" || true + fi : # null operation (no sleep needed) done + flag_remove "silentUnpacker" + "$SYSTEM_EMIT" process archiveUnpacker "FINISH_UNPACKING_REMOVE_SILENT" "helperFunctions.sh/finish_unpacking" "flag=$flag" || true + "$SYSTEM_EMIT" process archiveUnpacker "FINISH_UNPACKING_COMPLETE" "helperFunctions.sh/finish_unpacking" "flag=$flag loops=$wait_loops" || true stop_pyui_message_writer fi } @@ -662,6 +672,7 @@ get_config_value() { start_pyui_message_writer() { # $1 = 0 to not wait, anything else to wait wait_for_listener="$1" + "$SYSTEM_EMIT" process helperFunctions "PYUI_WRITER_START_REQUEST" "helperFunctions.sh/start_pyui_message_writer" "wait_for_listener=${wait_for_listener:-unset}" || true ifconfig lo up ifconfig lo 127.0.0.1 @@ -669,12 +680,14 @@ start_pyui_message_writer() { # Check if PyUI is already running with the realtime port argument if pgrep -f "sgDisplayRealtimePort" >/dev/null; then log_message "Real Time message listener already running." + "$SYSTEM_EMIT" process helperFunctions "PYUI_WRITER_REUSE_LISTENER" "helperFunctions.sh/start_pyui_message_writer" "listener already running" || true return fi rm -f /mnt/SDCARD/App/PyUI/realtime_message_network_listener.txt log_message "Starting Real Time message listener on port 50980" /mnt/SDCARD/App/PyUI/launch.sh -msgDisplayRealtimePort 50980 & + "$SYSTEM_EMIT" process helperFunctions "PYUI_WRITER_LAUNCHED" "helperFunctions.sh/start_pyui_message_writer" "pid=$!" || true # Optional wait for the listener file if [ "$wait_for_listener" != "0" ]; then @@ -683,6 +696,7 @@ start_pyui_message_writer() { sleep 0.1 done log_message "Realtime message network listener detected." + "$SYSTEM_EMIT" process helperFunctions "PYUI_WRITER_HANDSHAKE_COMPLETE" "helperFunctions.sh/start_pyui_message_writer" "listener file detected" || true fi } @@ -691,9 +705,11 @@ kill_pyui_message_writer() { # Check if PyUI is already running with the realtime port argument pids=$(pgrep -f "sgDisplayRealtimePort" | awk '{print $1}') + "$SYSTEM_EMIT" process helperFunctions "PYUI_WRITER_KILL_TARGETS" "helperFunctions.sh/kill_pyui_message_writer" "target_pids=${pids:-none}" || true if [ -n "$pids" ]; then log_message "Real Time message listener is running. Killing it..." + "$SYSTEM_EMIT" process helperFunctions "PYUI_WRITER_KILL_SIGNAL" "helperFunctions.sh/kill_pyui_message_writer" "sending EXIT_APP before kill" || true display_message "$(printf '{"cmd":"EXIT_APP","args":[]}')" sleep 0.5 @@ -703,6 +719,7 @@ kill_pyui_message_writer() { done # Optionally wait for processes to exit sleep 1 + "$SYSTEM_EMIT" process helperFunctions "PYUI_WRITER_KILL_COMPLETE" "helperFunctions.sh/kill_pyui_message_writer" "kill sequence complete" || true fi } @@ -901,18 +918,43 @@ set_network_proxy() { fi } +_log_scummvm_display_text() { + # $1 = IS_SCUMMVM_SECTION (0|1), $2 = log path, $3 = message + [ "$1" -eq 1 ] || return 0 + mkdir -p "/mnt/SDCARD/Saves/spruce" 2>/dev/null + printf '%s - %s\n' "$(date '+%Y-%m-%d %H:%M:%S')" "$3" >> "$2" +} + extract_7z_with_progress() { UPDATE_FILE="$1" DEST_DIR="$2" LOG_LOCATION="$3" # Only logs errors - DISPLAY_LABEL="$4" # Optional: static label to show instead of filenames + SECTION_LABEL="$4" # Optional: section title used in "Unpacking
" if [ -z "$UPDATE_FILE" ] || [ -z "$DEST_DIR" ] || [ -z "$LOG_LOCATION" ]; then - echo "Usage: extract_7z_with_progress [display_label]" + echo "Usage: extract_7z_with_progress [section_label]" return 1 fi - LOGO="/mnt/SDCARD/spruce/imgs/tree_sm_close_crop.png" + DEFAULT_ICON="/mnt/SDCARD/spruce/imgs/tree_sm_close_crop.png" + PORTMASTER_ICON="/mnt/SDCARD/App/PortMaster/portmaster.png" + SCUMMVM_ICON="/mnt/SDCARD/Emu/SCUMMVM/scummvm.png" + LOGO="$DEFAULT_ICON" + SCUMMVM_DISPLAY_TEXT_LOG="/mnt/SDCARD/Saves/spruce/scummvm_display_text.log" + if [ -z "$SECTION_LABEL" ]; then + SECTION_LABEL="$(basename "$UPDATE_FILE" .7z)" + fi + IS_SCUMMVM_SECTION=0 + case "$SECTION_LABEL" in + [Pp][Oo][Rr][Tt][Mm][Aa][Ss][Tt][Ee][Rr]) LOGO="$PORTMASTER_ICON" ;; + [Ss][Cc][Uu][Mm][Mm][Vv][Mm]) IS_SCUMMVM_SECTION=1 ; LOGO="$SCUMMVM_ICON" ;; + esac + + if [ "${SPRUCE_FIRSTBOOT_UI:-0}" = "1" ]; then + SECTION_TITLE="Sprucing up your device...\nUnpacking ${SECTION_LABEL}" + else + SECTION_TITLE="Unpacking ${SECTION_LABEL}" + fi TOTAL_FILES=$(7zr l -scsUTF-8 "$UPDATE_FILE" | awk '$1 ~ /^[0-9][0-9][0-9][0-9]-/ { count++ } END { print count }') @@ -929,19 +971,33 @@ extract_7z_with_progress() { return 1 fi + display_image_and_text "$LOGO" 35 25 "${SECTION_TITLE}\nPreparing extraction..." 75 + _log_scummvm_display_text "$IS_SCUMMVM_SECTION" "$SCUMMVM_DISPLAY_TEXT_LOG" "${SECTION_TITLE} | Preparing extraction..." + sleep 2 + 7zr x -y -scsUTF-8 -bb1 -o"$DEST_DIR" "$UPDATE_FILE" 2>>"$LOG_LOCATION" | while read -r line || [ -n "$line" ]; do - FILE=$(echo "$line" | sed 's/^[-[:space:]]*//') + case "$line" in + "- "*) FILE="${line#- }" ;; + "Extracting "*) FILE="${line#Extracting }" ;; + "Inflating "*) FILE="${line#Inflating }" ;; + *) continue ;; + esac [ -z "$FILE" ] && continue FILE_COUNT=$((FILE_COUNT + 1)) PERCENT_COMPLETE=$((FILE_COUNT * 100 / TOTAL_FILES)) + [ "$PERCENT_COMPLETE" -gt 100 ] && PERCENT_COMPLETE=100 if [ $((FILE_COUNT % THROTTLE)) -eq 0 ] || [ "$FILE_COUNT" -eq "$TOTAL_FILES" ]; then - display_text_with_percentage_bar \ - "${DISPLAY_LABEL:-$FILE}" \ - "$PERCENT_COMPLETE" \ - "$FILE_COUNT / $TOTAL_FILES files" + FILE_NAME="$(basename "$FILE")" + display_image_and_text \ + "$LOGO" \ + 35 25 \ + "${SECTION_TITLE}\n${PERCENT_COMPLETE}%: ${FILE_NAME}" \ + 75 + _log_scummvm_display_text "$IS_SCUMMVM_SECTION" "$SCUMMVM_DISPLAY_TEXT_LOG" \ + "${SECTION_TITLE} | ${PERCENT_COMPLETE}%: ${FILE_NAME}" fi done @@ -951,9 +1007,12 @@ extract_7z_with_progress() { log_update_message "Warning: Some files may have been skipped during extraction. Check $LOG_LOCATION for details." display_image_and_text "$LOGO" 35 25 \ "Extraction completed with warnings. Check the log for details." 75 + _log_scummvm_display_text "$IS_SCUMMVM_SECTION" "$SCUMMVM_DISPLAY_TEXT_LOG" \ + "Extraction completed with warnings. Check the log for details." else log_update_message "Extraction process completed successfully" display_image_and_text "$LOGO" 35 25 "Extraction completed!" 75 + _log_scummvm_display_text "$IS_SCUMMVM_SECTION" "$SCUMMVM_DISPLAY_TEXT_LOG" "Extraction completed!" fi return "$RET" @@ -1154,4 +1213,3 @@ log_activity_event() { printf '{"ts":%s,"event":"%s","app":"%s","pid":%s}\n' \ "$ts" "$event" "$safe_app" "$pid" >> "$LOG_FILE" } - diff --git a/spruce/scripts/low_power_warning.sh b/spruce/scripts/low_power_warning.sh index 484323544..1e392ba10 100644 --- a/spruce/scripts/low_power_warning.sh +++ b/spruce/scripts/low_power_warning.sh @@ -1,6 +1,7 @@ #!/bin/sh . /mnt/SDCARD/spruce/scripts/helperFunctions.sh +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" SLEEP=30 @@ -108,6 +109,7 @@ while true; do [ "$PERCENT" = "Off" ] && sleep $SLEEP && continue if [ "$CAPACITY" -le "$PERCENT" ]; then + "$SYSTEM_EMIT" power "RUNNING" "LOW_BATTERY" "low_power_warning.sh" "battery ${CAPACITY}% at or below threshold ${PERCENT}%" || true vibrate_count=0 flag_added=false while [ "$CAPACITY" -le "$PERCENT" ]; do diff --git a/spruce/scripts/networkservices.sh b/spruce/scripts/networkservices.sh index 14ef491e4..52cb87b87 100644 --- a/spruce/scripts/networkservices.sh +++ b/spruce/scripts/networkservices.sh @@ -5,6 +5,7 @@ . /mnt/SDCARD/spruce/scripts/network/sftpgoFunctions.sh . /mnt/SDCARD/spruce/scripts/network/syncthingFunctions.sh . /mnt/SDCARD/spruce/scripts/network/darkhttpdFunctions.sh +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" SFTP_SERVICE_NAME=$(get_sftp_service_name) SSH_SERVICE_NAME=$(get_ssh_service_name) @@ -22,6 +23,7 @@ connect_services() { fi sleep 0.5 done + "$SYSTEM_EMIT" network "ENABLED" "CONNECTED" "networkservices.sh/connect_services" "IP confirmed internet reachable" || true # Samba check if [ "$samba_enabled" = "True" ]; then @@ -69,7 +71,7 @@ connect_services() { } disconnect_services() { - + "$SYSTEM_EMIT" network "CONNECTED" "DISABLED" "networkservices.sh/disconnect_services" "stopping all network services" || true log_message "Network services: Stopping all network services..." for service in "$SFTP_SERVICE_NAME" "$SSH_SERVICE_NAME" "smbd" "syncthing" "darkhttpd"; do if pgrep "$service" >/dev/null; then diff --git a/spruce/scripts/platform/device_functions/AnbernicXXCommon.sh b/spruce/scripts/platform/device_functions/AnbernicXXCommon.sh index 75383c059..9b058dfb8 100644 --- a/spruce/scripts/platform/device_functions/AnbernicXXCommon.sh +++ b/spruce/scripts/platform/device_functions/AnbernicXXCommon.sh @@ -12,6 +12,7 @@ . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/watchdog_launcher.sh" . "/mnt/SDCARD/spruce/scripts/retroarch_utils.sh" . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/sleep_functions.sh" +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" get_config_path() { echo "$SYSTEM_JSON" @@ -202,6 +203,7 @@ set_volume() { system_volume=$(( (new_vol * 31 + 10) / 20 )) amixer -q set 'lineout volume' "$system_volume" + "$SYSTEM_EMIT" audio-level "$new_vol" "AnbernicXXCommon.sh/set_volume" 2>/dev/null || true if [ "$SAVE_TO_CONFIG" = true ]; then current_volume=$(jq -r '.vol' "$SYSTEM_JSON") @@ -291,4 +293,4 @@ setup_for_retroarch_and_get_bin_location(){ prepare_for_pyui_launch(){ # Where else to put this? dhclient wlan0 -} \ No newline at end of file +} diff --git a/spruce/scripts/platform/device_functions/MiyooMini.sh b/spruce/scripts/platform/device_functions/MiyooMini.sh index 1d0c52969..88c030a5b 100644 --- a/spruce/scripts/platform/device_functions/MiyooMini.sh +++ b/spruce/scripts/platform/device_functions/MiyooMini.sh @@ -7,6 +7,7 @@ . "/mnt/SDCARD/spruce/scripts/platform/device_functions/common32bit.sh" . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/watchdog_launcher.sh" +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" get_config_path() { echo "/mnt/SDCARD/Saves/mini-flip-system.json" @@ -226,6 +227,7 @@ set_backlight() { jq ".backlight = $value" "$SYSTEM_JSON" > "$SYSTEM_JSON.tmp" && mv "$SYSTEM_JSON.tmp" "$SYSTEM_JSON" # Should we get this from path or always from PyUI? /mnt/SDCARD/App/PyUI/main-ui/devices/miyoo/mini/set_shared_memory 1 "$value" + "$SYSTEM_EMIT" brightness-level "$value" "MiyooMini.sh/set_backlight" 2>/dev/null || true } brightness_down() { @@ -376,4 +378,4 @@ device_system_handles_sdcard_unmount() { # return 0 = true # return non-zero = false return 0 -} \ No newline at end of file +} diff --git a/spruce/scripts/platform/device_functions/Pixel2.sh b/spruce/scripts/platform/device_functions/Pixel2.sh index ce653ee4f..72172c117 100755 --- a/spruce/scripts/platform/device_functions/Pixel2.sh +++ b/spruce/scripts/platform/device_functions/Pixel2.sh @@ -10,6 +10,7 @@ . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/cpu_control_functions.sh" . "/mnt/SDCARD/spruce/scripts/retroarch_utils.sh" . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/sleep_functions.sh" +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" get_sftp_service_name() { echo "sftpgo" @@ -275,6 +276,7 @@ set_backlight() { if (( $new_bl >= 0 )) && (( $new_bl <= 10 )); then echo $sys_bl > $DEVICE_BRIGHTNESS_PATH jq ".backlight = $new_bl" "$SYSTEM_JSON" > "$SYSTEM_JSON.tmp" && mv "$SYSTEM_JSON.tmp" "$SYSTEM_JSON" + "$SYSTEM_EMIT" brightness-level "$new_bl" "Pixel2.sh/set_backlight" 2>/dev/null || true fi } diff --git a/spruce/scripts/platform/device_functions/SmartProS.sh b/spruce/scripts/platform/device_functions/SmartProS.sh index 3d278b0d3..e6bbafa7f 100644 --- a/spruce/scripts/platform/device_functions/SmartProS.sh +++ b/spruce/scripts/platform/device_functions/SmartProS.sh @@ -8,6 +8,7 @@ . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/watchdog_launcher.sh" . "/mnt/SDCARD/spruce/scripts/retroarch_utils.sh" . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/sleep_functions.sh" +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" get_config_path() { echo "/mnt/SDCARD/Saves/trim-ui-smart-pro-s-system.json" @@ -490,6 +491,7 @@ set_backlight() { # update device system json tmp=$(mktemp) jq ".backlight = $val" "$SYSTEM_JSON" > "$tmp" && mv "$tmp" "$SYSTEM_JSON" + "$SYSTEM_EMIT" brightness-level "$val" "SmartProS.sh/set_backlight" 2>/dev/null || true } diff --git a/spruce/scripts/platform/device_functions/trimui_a133p.sh b/spruce/scripts/platform/device_functions/trimui_a133p.sh index d55d45343..870dcb387 100644 --- a/spruce/scripts/platform/device_functions/trimui_a133p.sh +++ b/spruce/scripts/platform/device_functions/trimui_a133p.sh @@ -8,6 +8,7 @@ . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/watchdog_launcher.sh" . "/mnt/SDCARD/spruce/scripts/retroarch_utils.sh" . "/mnt/SDCARD/spruce/scripts/platform/device_functions/utils/sleep_functions.sh" +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" ############################################################################### @@ -273,6 +274,7 @@ EOF tmp=$(mktemp) jq ".backlight = $val" "$SYSTEM_JSON" > "$tmp" && mv "$tmp" "$SYSTEM_JSON" + "$SYSTEM_EMIT" brightness-level "$val" "trimui_a133p.sh/set_backlight" 2>/dev/null || true } @@ -280,4 +282,4 @@ device_system_handles_sdcard_unmount() { # return 0 = true # return non-zero = false return 1 # Brick/SmartPro leaves dirty bit set? -} \ No newline at end of file +} diff --git a/spruce/scripts/principal.sh b/spruce/scripts/principal.sh index 9505fb1c8..64e0b1330 100644 --- a/spruce/scripts/principal.sh +++ b/spruce/scripts/principal.sh @@ -58,6 +58,36 @@ while [ 1 ]; do # When you select a game or app, MainUI writes that command to a temp file and closes itself. # This section handles what becomes of that temp file. if [ -f /tmp/cmd_to_run.sh ]; then + is_autoresume_launch=0 + if flag_check "autoresume_staged"; then + is_autoresume_launch=1 + if flag_check "autoresume_consumed"; then + log_message "Auto Resume contract violation prevented: staged command already consumed once in this boot; removing duplicate /tmp/cmd_to_run.sh" + rm -f /tmp/cmd_to_run.sh + flag_remove "autoresume_staged" + continue + fi + flag_add "autoresume_consumed" --tmp + fi + + if [ ! -s /tmp/cmd_to_run.sh ]; then + log_message "cmd_to_run rejected: empty or invalid file; removing and continuing to menu." + rm -f /tmp/cmd_to_run.sh + [ "$is_autoresume_launch" -eq 1 ] && flag_remove "autoresume_staged" + continue + fi + + if ! sh -n /tmp/cmd_to_run.sh >/dev/null 2>&1; then + log_message "cmd_to_run rejected: syntax check failed; removing and continuing to menu." + rm -f /tmp/cmd_to_run.sh + [ "$is_autoresume_launch" -eq 1 ] && flag_remove "autoresume_staged" + continue + fi + + if [ "$is_autoresume_launch" -eq 1 ]; then + log_message "Auto Resume consume start: staged file accepted by canonical launcher" + fi + sync cmd="$(sed 's/[[:space:]]*$//' /tmp/cmd_to_run.sh)" log_activity_event "$cmd" "START" @@ -69,12 +99,22 @@ while [ 1 ]; do cp /tmp/cmd_to_run.sh "$FLAGS_DIR/lastgame.lock" # set up autoresume log_message "Running: $(cat /tmp/cmd_to_run.sh)" /tmp/cmd_to_run.sh >/dev/null 2>&1 + cmd_exit_code=$? rm /tmp/cmd_to_run.sh + if [ -f /tmp/cmd_to_run.sh ]; then + rm -f /tmp/cmd_to_run.sh + log_message "cmd_to_run cleanup required second removal attempt" + fi rm /tmp/host_msg 2>/dev/null rm /tmp/miyoo_inputd/enable_turbo_input 2>/dev/null # Disables turbo buttons in menu for Flip killall -9 udpbcast 2>/dev/null + if [ "$is_autoresume_launch" -eq 1 ]; then + flag_remove "autoresume_staged" + log_message "Auto Resume consume complete: launched once via principal, exit_code=$cmd_exit_code, staged artifact removed" + fi + log_activity_event "$cmd" "STOP" sync fi diff --git a/spruce/scripts/runtime.sh b/spruce/scripts/runtime.sh index 4a66f8dc7..7248b02d5 100644 --- a/spruce/scripts/runtime.sh +++ b/spruce/scripts/runtime.sh @@ -10,6 +10,43 @@ . /mnt/SDCARD/spruce/scripts/helperFunctions.sh . /mnt/SDCARD/spruce/scripts/runtimeHelper.sh +. /mnt/SDCARD/spruce/scripts/trace.sh +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" + +UNPACK_STATE_FILE="/mnt/SDCARD/Saves/spruce/unpacker_state" + +read_unpack_state() { + if [ -f "$UNPACK_STATE_FILE" ]; then + sed -n 's/^state=//p' "$UNPACK_STATE_FILE" | head -n 1 + else + echo "idle" + fi +} + +run_unpacker_foreground() { + launch_event="$1" + launch_context="$2" + result_event="$3" + log_prefix="$4" + allow_background_state="$5" + force_foreground_precmd="$6" + firstboot_ui="$7" + + "$SYSTEM_EMIT" process archiveUnpacker "$launch_event" "runtime.sh" "$launch_context" || true + if [ "$force_foreground_precmd" = "1" ]; then + SPRUCE_FIRSTBOOT_UI="${firstboot_ui:-0}" UNPACKER_FORCE_FOREGROUND_PRECMD=1 /mnt/SDCARD/spruce/scripts/archiveUnpacker.sh + else + SPRUCE_FIRSTBOOT_UI="${firstboot_ui:-0}" /mnt/SDCARD/spruce/scripts/archiveUnpacker.sh + fi + + unpack_state="$(read_unpack_state)" + if [ "$allow_background_state" = "1" ] && [ "$unpack_state" = "running" ]; then + log_message "Unpacker: $log_prefix returned with background worker still active." + else + log_message "Unpacker: $log_prefix returned with state=$unpack_state." + fi + "$SYSTEM_EMIT" process archiveUnpacker "$result_event" "runtime.sh" "state=$unpack_state" || true +} [ "$LED_PATH" != "not applicable" ] && echo mmc0 > "$LED_PATH"/trigger @@ -18,6 +55,8 @@ export HOME="/mnt/SDCARD" rotate_logs log_file="/mnt/SDCARD/Saves/spruce/spruce.log" # Resetting log file location log_message "---------Starting up---------" +trace_fsm_boot_init "runtime.sh" || true +emit_startup_av_trace_from_config || true run_sd_card_fix_if_triggered # do this before anything else set_performance @@ -35,22 +74,49 @@ unstage_archives_wanted check_and_handle_firmware_app & check_and_hide_update_app & -# Check for first_boot flags and run Unpacker accordingly +# Check for first_boot flags and run extraction in a deterministic sequence. +# firstboot handles package extraction (PortMaster/ScummVM), then archiveUnpacker +# runs in foreground for themes/preMenu/preCmd so extraction paths do not overlap. if flag_check "first_boot_${PLATFORM}"; then - /mnt/SDCARD/spruce/scripts/archiveUnpacker.sh --silent & - log_message "Unpacker started silently in background due to first_boot flag" - "/mnt/SDCARD/spruce/scripts/firstboot.sh" + "$SYSTEM_EMIT" process firstboot "ENTER_FIRSTBOOT_SCRIPT" "runtime.sh" "sequential extraction phase: packages" || true + SPRUCE_FIRSTBOOT_UI=1 "/mnt/SDCARD/spruce/scripts/firstboot.sh" + "$SYSTEM_EMIT" process firstboot "EXIT_FIRSTBOOT_SCRIPT" "runtime.sh" "returned from firstboot.sh" || true + + run_unpacker_foreground \ + "FIRSTBOOT_FOREGROUND_LAUNCH" \ + "sequential extraction after firstboot" \ + "FIRSTBOOT_FOREGROUND_RESULT" \ + "firstboot foreground run" \ + "0" \ + "1" \ + "1" + display_image_and_text "/mnt/SDCARD/spruce/imgs/smile.png" 35 25 "Happy gaming.........." 75 + sleep 5 else - /mnt/SDCARD/spruce/scripts/archiveUnpacker.sh + run_unpacker_foreground \ + "FOREGROUND_LAUNCH" \ + "non-first_boot path" \ + "FOREGROUND_RESULT" \ + "foreground run" \ + "1" \ + "0" \ + "0" fi /mnt/SDCARD/spruce/scripts/set_up_swap.sh & launch_startup_watchdogs +"$SYSTEM_EMIT" process runtime "STARTUP_WATCHDOGS_LAUNCHED" "runtime.sh" "startup_watchdogs launched" || true # check whether to auto-resume into a game +auto_resume_staged=0 if flag_check "save_active"; then - auto_resume_game + if auto_resume_game; then + auto_resume_staged=1 + log_message "Auto Resume contract: staged intent in runtime helper; principal.sh owns execution." + else + log_message "Auto Resume contract: staging failed; continuing with normal runtime/menu path." + fi else log_message "Auto Resume skipped (no save_active flag)" fi @@ -66,6 +132,13 @@ set_smart # Set up the boot_to action prior to getting into the principal loop set_up_boot_action +if flag_check "save_active"; then + if [ "$auto_resume_staged" -eq 1 ]; then + log_message "save_active cleared by runtime after successful stage handoff to principal.sh" + else + log_message "save_active cleared by runtime without stage handoff (fallback path)" + fi +fi flag_remove "save_active" # start main loop diff --git a/spruce/scripts/runtimeHelper.sh b/spruce/scripts/runtimeHelper.sh index f744aff84..cd8c6fbf1 100644 --- a/spruce/scripts/runtimeHelper.sh +++ b/spruce/scripts/runtimeHelper.sh @@ -3,6 +3,7 @@ . /mnt/SDCARD/spruce/scripts/helperFunctions.sh . /mnt/SDCARD/spruce/scripts/network/sambaFunctions.sh . /mnt/SDCARD/spruce/scripts/network/sshFunctions.sh +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" run_sd_card_fix_if_triggered() { needs_fix=false @@ -369,24 +370,106 @@ set_volume_to_config() { [ -n "$vol" ] && set_volume "$vol" } +emit_startup_av_trace_from_config() { + "$SYSTEM_EMIT" av-startup-baselines-if-missing "runtimeHelper.sh" || true +} + auto_resume_game() { - log_message "save_active flag detected. Autoresuming game." + AUTORESUME_ID="$(date +%s)-$$" + save_active_state="0"; flag_check "save_active" && save_active_state="1" + in_menu_state="0"; flag_check "in_menu" && in_menu_state="1" + log_message "Auto Resume[$AUTORESUME_ID] start: save_active=$save_active_state in_menu=$in_menu_state" # Ensure device is properly initialized (volume, wifi, etc) before launching auto-resume - /mnt/SDCARD/App/PyUI/launch.sh -startupInitOnly True + AUTORESUME_INIT_TIMEOUT_SEC=20 + log_message "Auto Resume[$AUTORESUME_ID] init start: launching PyUI startupInitOnly timeout=${AUTORESUME_INIT_TIMEOUT_SEC}s" + /mnt/SDCARD/App/PyUI/launch.sh -startupInitOnly True & + init_pid="$!" + init_timed_out=0 + init_degraded=0 + init_start_ts="$(date +%s)" + init_next_heartbeat=2 + log_message "Auto Resume[$AUTORESUME_ID] init pid=$init_pid" + while kill -0 "$init_pid" 2>/dev/null; do + now_ts="$(date +%s)" + elapsed=$((now_ts - init_start_ts)) + if [ "$elapsed" -ge "$init_next_heartbeat" ]; then + log_message "Auto Resume[$AUTORESUME_ID] init wait heartbeat: elapsed=${elapsed}s pid=$init_pid alive=1" + init_next_heartbeat=$((init_next_heartbeat + 2)) + fi + if [ "$elapsed" -ge "$AUTORESUME_INIT_TIMEOUT_SEC" ]; then + init_timed_out=1 + listener_state="absent" + [ -f /mnt/SDCARD/App/PyUI/realtime_message_network_listener.txt ] && listener_state="present" + init_cmdline="unavailable" + if [ -r "/proc/$init_pid/cmdline" ]; then + init_cmdline="$(tr '\000' ' ' < "/proc/$init_pid/cmdline" 2>/dev/null)" + [ -z "$init_cmdline" ] && init_cmdline="empty" + fi + init_ps="unavailable" + if command -v ps >/dev/null 2>&1; then + init_ps="$(ps 2>/dev/null | awk -v p="$init_pid" '$1==p{print; found=1} END{if(!found) print "not-found"}')" + fi + log_message "Auto Resume[$AUTORESUME_ID] init timeout: startupInitOnly exceeded ${AUTORESUME_INIT_TIMEOUT_SEC}s (pid=$init_pid); listener=$listener_state cmdline=$init_cmdline ps=$init_ps" + kill "$init_pid" 2>/dev/null || true + sleep 1 + kill -9 "$init_pid" 2>/dev/null || true + if kill -0 "$init_pid" 2>/dev/null; then + log_message "Auto Resume[$AUTORESUME_ID] init kill result: pid still alive after SIGTERM+SIGKILL" + else + log_message "Auto Resume[$AUTORESUME_ID] init kill result: pid exited after timeout" + fi + break + fi + sleep 0.2 + done + wait "$init_pid" 2>/dev/null + init_rc="$?" + if [ "$init_timed_out" -eq 1 ]; then + init_degraded=1 + log_message "Auto Resume[$AUTORESUME_ID] init degraded: continuing resume stage without startupInitOnly completion wait_rc=$init_rc" + else + log_message "Auto Resume[$AUTORESUME_ID] init complete: startupInitOnly exit_code=$init_rc" + fi # moving rather than copying prevents you from repeatedly reloading into a corrupted NDS save state; # copying is necessary for repeated save+shutdown/autoresume chaining though and is preferred when safe. MOVE_OR_COPY=cp if grep -q "Roms/NDS" "${FLAGS_DIR}/lastgame.lock"; then MOVE_OR_COPY=mv; fi - # move command to cmd_to_run.sh so game switcher can work correctly - $MOVE_OR_COPY "/mnt/SDCARD/spruce/flags/lastgame.lock" /tmp/cmd_to_run.sh && sync + # runtimeHelper producer contract: + # stage once and hand off; principal.sh owns execution and cleanup. + AUTORESUME_STAGED_FLAG="autoresume_staged" + AUTORESUME_CONSUMED_FLAG="autoresume_consumed" + STAGED_PATH="/tmp/cmd_to_run.sh" + STAGED_TMP="/tmp/cmd_to_run.sh.autoresume.tmp" - sleep 4 - nice -n -20 /tmp/cmd_to_run.sh &> /dev/null - rm -f /tmp/cmd_to_run.sh # remove tmp command file after game exit; otherwise the game will load again in principal.sh later - log_message "Auto Resume executed" + if flag_check "$AUTORESUME_STAGED_FLAG"; then + log_message "Auto Resume[$AUTORESUME_ID] stage skipped: existing staged marker already present." + return 1 + fi + + rm -f "$STAGED_TMP" "$STAGED_PATH" + log_message "Auto Resume[$AUTORESUME_ID] stage attempt: source=/mnt/SDCARD/spruce/flags/lastgame.lock target=$STAGED_PATH mode=$MOVE_OR_COPY degraded_init=$init_degraded" + if $MOVE_OR_COPY "/mnt/SDCARD/spruce/flags/lastgame.lock" "$STAGED_TMP"; then + mv -f "$STAGED_TMP" "$STAGED_PATH" || return 1 + chmod a+x "$STAGED_PATH" + flag_add "$AUTORESUME_STAGED_FLAG" --tmp + flag_remove "$AUTORESUME_CONSUMED_FLAG" + sync + if [ "$init_degraded" -eq 1 ]; then + log_message "Auto Resume[$AUTORESUME_ID] staged for principal.sh execution (degraded_init=1 stage_once=1 path=$STAGED_PATH)" + else + log_message "Auto Resume[$AUTORESUME_ID] staged for principal.sh execution (stage_once=1 path=$STAGED_PATH)" + fi + else + rm -f "$STAGED_TMP" "$STAGED_PATH" + flag_remove "$AUTORESUME_STAGED_FLAG" + log_message "Auto Resume[$AUTORESUME_ID] staging failed (lastgame.lock copy/move failed); fallback to normal menu boot path." + return 1 + fi + + return 0 } set_up_boot_action() { @@ -424,4 +507,4 @@ set_up_boot_action() { ;; esac fi -} \ No newline at end of file +} diff --git a/spruce/scripts/save_poweroff.sh b/spruce/scripts/save_poweroff.sh index a516d9d6b..61731b4fe 100644 --- a/spruce/scripts/save_poweroff.sh +++ b/spruce/scripts/save_poweroff.sh @@ -4,6 +4,8 @@ . /mnt/SDCARD/spruce/scripts/helperFunctions.sh . /mnt/SDCARD/spruce/scripts/network/syncthingFunctions.sh +. /mnt/SDCARD/spruce/scripts/trace.sh +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" FLAGS_DIR="/mnt/SDCARD/spruce/flags" BG_TREE="/mnt/SDCARD/spruce/imgs/tree_sm_close_crop.png" @@ -241,8 +243,10 @@ clean_up_flags() { # Set flag to trigger autoresume on boot if appropriate if flag_check "in_menu"; then flag_remove "save_active" + log_message "save_active cleared by save_poweroff: shutdown initiated from menu" else flag_add "save_active" + log_message "save_active set by save_poweroff: shutdown initiated outside menu" fi flag_remove "sleep.powerdown" flag_remove "emulator_launched" @@ -266,6 +270,11 @@ exec_shutdown_stage_2() { fi } + +emit_shutdown_av_trace_fallback() { + "$SYSTEM_EMIT" av-shutdown-baselines-if-missing "save_poweroff.sh" || true +} + ####################################### ##### PREVENT RE-ENTRY IF ALREADY RUNNING ##### ####################################### @@ -287,6 +296,9 @@ trap 'rm -f "$PIDFILE"' EXIT INT TERM ################### MAIN ###################### ######## +"$SYSTEM_EMIT" power-shutdown-request "$s2_arg" "save_poweroff.sh" "shutdown triggered" || true +emit_shutdown_av_trace_fallback || true +trace_fsm_shutdown_finalize "save_poweroff.sh" || true blink_led_if_applicable device_prepare_for_poweroff log_activity_event "$(get_current_app)" "STOP" diff --git a/spruce/scripts/sleep_helper.sh b/spruce/scripts/sleep_helper.sh index e14612948..4e7958d19 100644 --- a/spruce/scripts/sleep_helper.sh +++ b/spruce/scripts/sleep_helper.sh @@ -1,6 +1,7 @@ #!/bin/sh . /mnt/SDCARD/spruce/scripts/helperFunctions.sh +SYSTEM_EMIT="${SYSTEM_EMIT:-/mnt/SDCARD/spruce/scripts/system-emit}" if [ -e /tmp/sleep_helper_started ]; then log_message "Sleep helper already active, skipping. /tmp/sleep_helper_started exists" -v @@ -68,8 +69,30 @@ get_shutdown_timer() { } +read_system_json_int() { + key="$1" + + if [ -z "${SYSTEM_JSON:-}" ] || [ ! -f "$SYSTEM_JSON" ]; then + return 1 + fi + if ! command -v jq >/dev/null 2>&1; then + return 1 + fi + + value="$(jq -r "$key // empty" "$SYSTEM_JSON" 2>/dev/null || true)" + case "$value" in + ''|*[!0-9]*) + return 1 + ;; + esac + + printf '%s\n' "$value" + return 0 +} + trigger_sleep() { log_message "Entering sleep" + "$SYSTEM_EMIT" power "RUNNING" "SLEEP" "sleep_helper.sh" "entering sleep" || true lid_ever_closed=false sleep_exited=false # Get the lid powerdown timeout @@ -77,6 +100,8 @@ trigger_sleep() { IDLE_TIMEOUT=$(get_shutdown_timer) start_ts=$(date +%s) set_volume 0 false # Mute on sleep so when we wake to shutdown it's silent + "$SYSTEM_EMIT" audio-from-current-to-cached-or-unknown "0" "sleep_helper.sh" "muted on sleep entry" || true + "$SYSTEM_EMIT" brightness-cached-or-unknown "sleep_helper.sh" "brightness baseline cached or unavailable on sleep entry" || true device_enter_sleep "$IDLE_TIMEOUT" if [ "$(device_uses_pseudo_sleep)" = "true" ]; then log_message "Device uses pseudosleep -- starting idle loop" @@ -146,12 +171,19 @@ trigger_sleep() { trigger_sleep device_exit_sleep +"$SYSTEM_EMIT" power "SLEEP" "RUNNING" "sleep_helper.sh" "woke from sleep" || true log_activity_event "$current_app" "START" # Restore volume before unpausing so audio is ready -VOLUME_LV=$(jq -r '.vol' "$SYSTEM_JSON") -set_volume "$VOLUME_LV" +VOLUME_LV="$(read_system_json_int '.vol' || true)" +case "$VOLUME_LV" in + ''|*[!0-9]*) ;; + *) set_volume "$VOLUME_LV" ;; +esac +"$SYSTEM_EMIT" audio-wake-restore "0" "$VOLUME_LV" "sleep_helper.sh" || true +WAKE_BL="$(read_system_json_int '.backlight' || true)" +"$SYSTEM_EMIT" brightness-wake-baseline "$WAKE_BL" "sleep_helper.sh" || true kill "$GET_EVENT_PID" 2>/dev/null diff --git a/spruce/scripts/system-emit b/spruce/scripts/system-emit new file mode 100755 index 000000000..882a7974d --- /dev/null +++ b/spruce/scripts/system-emit @@ -0,0 +1,98 @@ +#!/bin/sh + +SCRIPT_DIR=$(CDPATH= cd -- "$(dirname "$0")" && pwd) +if [ -f "$SCRIPT_DIR/trace.sh" ]; then + # shellcheck disable=SC1091 + . "$SCRIPT_DIR/trace.sh" +else + . /mnt/SDCARD/spruce/scripts/trace.sh +fi +case "${1:-}" in + power) + shift + power_trace_emit "$@" + ;; + power-shutdown-request) + shift + power_trace_emit_shutdown_request "$@" + ;; + network) + shift + network_trace_emit "$@" + ;; + audio-level) + shift + audio_trace_emit_level "$@" + ;; + audio-levels) + shift + audio_trace_emit_levels "$@" + ;; + audio-cached-or-unknown) + shift + audio_trace_emit_cached_or_unknown "$@" + ;; + audio-from-current-to-cached-or-unknown) + shift + audio_trace_emit_from_current_to_cached_or_unknown "$@" + ;; + audio-startup-baseline-if-missing) + shift + audio_trace_emit_startup_baseline_if_missing "$@" + ;; + audio-shutdown-baseline-if-missing) + shift + audio_trace_emit_shutdown_baseline_if_missing "$@" + ;; + audio-wake-restore) + shift + audio_trace_emit_wake_restore "$@" + ;; + brightness-level) + shift + brightness_trace_emit_level "$@" + ;; + brightness-levels) + shift + brightness_trace_emit_levels "$@" + ;; + brightness-cached-or-unknown) + shift + brightness_trace_emit_cached_or_unknown "$@" + ;; + brightness-startup-baseline-if-missing) + shift + brightness_trace_emit_startup_baseline_if_missing "$@" + ;; + brightness-shutdown-baseline-if-missing) + shift + brightness_trace_emit_shutdown_baseline_if_missing "$@" + ;; + brightness-wake-baseline) + shift + brightness_trace_emit_wake_baseline "$@" + ;; + av-startup-baselines-if-missing) + shift + av_trace_emit_startup_baselines_if_missing "$@" + ;; + av-shutdown-baselines-if-missing) + shift + av_trace_emit_shutdown_baselines_if_missing "$@" + ;; + process-init) + shift + process_trace_init "$@" + ;; + process-finalize) + shift + process_trace_finalize "$@" + ;; + process) + shift + process_trace_emit "$@" + ;; + *) + printf '%s\n' "system-emit: unknown subcommand '${1:-}'" >&2 + exit 2 +esac diff --git a/spruce/scripts/trace.sh b/spruce/scripts/trace.sh new file mode 100644 index 000000000..5bd20aa2d --- /dev/null +++ b/spruce/scripts/trace.sh @@ -0,0 +1,1181 @@ +#!/bin/sh + +TRACE_ROOT="${TRACE_ROOT:-/mnt/SDCARD/Saves/spruce}" +TRACE_DIR="${TRACE_DIR:-$TRACE_ROOT/trace}" +TRACE_EVENTS_FILE="${TRACE_EVENTS_FILE:-$TRACE_DIR/events.jsonl}" +TRACE_SUMMARY_FILE="${TRACE_SUMMARY_FILE:-$TRACE_DIR/summary.txt}" +TRACE_STATE_FILE="${TRACE_STATE_FILE:-$TRACE_DIR/state.env}" +TRACE_MAX_EVENTS="${TRACE_MAX_EVENTS:-400}" +TRACE_MAX_SUMMARY_LINES="${TRACE_MAX_SUMMARY_LINES:-120}" +POWER_TRACE_DIR="${POWER_TRACE_DIR:-$TRACE_ROOT/power}" +POWER_TRACE_EVENTS_FILE="${POWER_TRACE_EVENTS_FILE:-$POWER_TRACE_DIR/events.jsonl}" +POWER_TRACE_SUMMARY_FILE="${POWER_TRACE_SUMMARY_FILE:-$POWER_TRACE_DIR/summary.txt}" +TRACE_ENABLED="${TRACE_ENABLED:-1}" +POWER_TRACE_ENABLED="${POWER_TRACE_ENABLED:-1}" +AUDIO_TRACE_ENABLED="${AUDIO_TRACE_ENABLED:-1}" +NETWORK_TRACE_ENABLED="${NETWORK_TRACE_ENABLED:-${WIFI_TRACE_ENABLED:-1}}" +BRIGHTNESS_TRACE_ENABLED="${BRIGHTNESS_TRACE_ENABLED:-1}" +PROCESS_TRACE_ENABLED="${PROCESS_TRACE_ENABLED:-1}" +TRACE_GATE_DIR="${TRACE_GATE_DIR:-/tmp/spruce_trace_gates}" +TRACE_STATE_FLUSH_INTERVAL="${TRACE_STATE_FLUSH_INTERVAL:-20}" +TRACE_TRIM_INTERVAL="${TRACE_TRIM_INTERVAL:-20}" +TRACE_FSM_DIR="${TRACE_FSM_DIR:-$TRACE_DIR/fsm}" +TRACE_CACHE_DIR="${TRACE_CACHE_DIR:-/tmp/spruce_trace_cache}" +# Maximum magnitude of a single audio/brightness step before it is flagged +# as a large jump. Set to 0 to disable the check for that subsystem. +AUDIO_LARGE_JUMP_THRESHOLD="${AUDIO_LARGE_JUMP_THRESHOLD:-5}" +BRIGHTNESS_LARGE_JUMP_THRESHOLD="${BRIGHTNESS_LARGE_JUMP_THRESHOLD:-3}" + +trace_state_loaded=0 +trace_dirs_ready=0 +trace_trim_counter=0 +trace_unknown_domain_warned="" +trace_cached_boot_id="" +trace_cached_build_id="" + +trace_normalize_subsystem() { + case "$1" in + wifi|network|networking) + printf '%s\n' "networking" + ;; + power|audio|brightness) + printf '%s\n' "$1" + ;; + *) + printf '%s\n' "$1" + ;; + esac +} + +trace_gate_enabled() { + subsystem="$(trace_normalize_subsystem "$1")" + + [ "$TRACE_ENABLED" = "0" ] && return 1 + [ -f "$TRACE_GATE_DIR/trace.off" ] && return 1 + + case "$subsystem" in + power) + [ "$POWER_TRACE_ENABLED" = "0" ] && return 1 + [ -f "$TRACE_GATE_DIR/power.off" ] && return 1 + ;; + audio) + [ "$AUDIO_TRACE_ENABLED" = "0" ] && return 1 + [ -f "$TRACE_GATE_DIR/audio.off" ] && return 1 + ;; + networking) + [ "$NETWORK_TRACE_ENABLED" = "0" ] && return 1 + [ -f "$TRACE_GATE_DIR/networking.off" ] && return 1 + [ -f "$TRACE_GATE_DIR/wifi.off" ] && return 1 + ;; + brightness) + [ "$BRIGHTNESS_TRACE_ENABLED" = "0" ] && return 1 + [ -f "$TRACE_GATE_DIR/brightness.off" ] && return 1 + ;; + process|process-*) + [ "$PROCESS_TRACE_ENABLED" = "0" ] && return 1 + [ -f "$TRACE_GATE_DIR/process.off" ] && return 1 + ;; + *) + case " $trace_unknown_domain_warned " in + *" $subsystem "*) + ;; + *) + trace_unknown_domain_warned="$trace_unknown_domain_warned $subsystem" + printf '%s\n' "trace_gate_enabled: unknown subsystem '$subsystem'" >&2 + ;; + esac + return 1 + ;; + esac + + return 0 +} + +trace_monotonic_ts() { + awk '{print $1}' /proc/uptime 2>/dev/null +} + +trace_wall_ts() { + date -u +"%Y-%m-%dT%H:%M:%SZ" +} + +trace_boot_id() { + if [ -z "$trace_cached_boot_id" ]; then + if [ -r /proc/sys/kernel/random/boot_id ]; then + trace_cached_boot_id="$(cat /proc/sys/kernel/random/boot_id 2>/dev/null)" + fi + [ -n "$trace_cached_boot_id" ] || trace_cached_boot_id="boot-unknown" + fi + printf '%s\n' "$trace_cached_boot_id" +} + +trace_build() { + if [ -z "$trace_cached_build_id" ]; then + trace_cached_build_id="$(cat /etc/version 2>/dev/null)" + [ -n "$trace_cached_build_id" ] || trace_cached_build_id="unknown" + fi + printf '%s\n' "$trace_cached_build_id" +} + +trace_escape_json() { + printf '%s' "$1" | sed 's/\\/\\\\/g; s/"/\\"/g' +} + +trace_trim_file() { + file="$1" + max_lines="$2" + [ -f "$file" ] || return 0 + count=$(wc -l < "$file" 2>/dev/null || echo 0) + if [ "$count" -gt "$max_lines" ]; then + tail -n "$max_lines" "$file" > "$file.tmp.$$" && mv "$file.tmp.$$" "$file" + fi +} + +trace_cache_state_file() { + subsystem="$(trace_normalize_subsystem "$1")" + printf '%s/%s.state\n' "$TRACE_CACHE_DIR" "$subsystem" +} + +trace_cache_read_state() { + cache_file="$(trace_cache_state_file "$1")" + if [ -r "$cache_file" ]; then + head -n 1 "$cache_file" 2>/dev/null + fi +} + +trace_cache_write_state() { + subsystem="$(trace_normalize_subsystem "$1")" + state="$2" + + case "$state" in + ''|UNKNOWN|AUTO) + return 0 + ;; + esac + + cache_file="$(trace_cache_state_file "$subsystem")" + mkdir -p "$TRACE_CACHE_DIR" 2>/dev/null || return 0 + printf '%s\n' "$state" > "$cache_file.tmp.$$" && mv "$cache_file.tmp.$$" "$cache_file" +} + +trace_load_state() { + [ "$trace_state_loaded" = "1" ] && return 0 + trace_ensure_dirs + if [ -f "$TRACE_STATE_FILE" ]; then + # shellcheck disable=SC1090 + . "$TRACE_STATE_FILE" + fi + [ -n "${trace_seq:-}" ] || trace_seq=0 + trace_state_loaded=1 +} + +trace_save_state() { + trace_ensure_dirs + umask 077 + cat > "$TRACE_STATE_FILE.tmp.$$" <> "$events_file" + printf '%s\n' "$summary_line" >> "$summary_file" + + trace_trim_counter=$((trace_trim_counter + 1)) + trim_interval="$TRACE_TRIM_INTERVAL" + case "$trim_interval" in + ''|*[!0-9]*) trim_interval=20 ;; + esac + if [ "$trim_interval" -le 1 ] || [ $((trace_trim_counter % trim_interval)) -eq 0 ]; then + trace_trim_file "$events_file" "$max_events" + trace_trim_file "$summary_file" "$max_summary" + fi +} + +trace_subsystem_dir() { + subsystem="$(trace_normalize_subsystem "$1")" + printf '%s/%s\n' "$TRACE_ROOT" "$subsystem" +} + +trace_subsystem_events_file() { + printf '%s/events.jsonl\n' "$(trace_subsystem_dir "$1")" +} + +trace_subsystem_summary_file() { + printf '%s/summary.txt\n' "$(trace_subsystem_dir "$1")" +} + +trace_build_json_line() { + seq="$1" + subsystem="$2" + current_state="$3" + requested_state="$4" + source_ref="$5" + context="$6" + ts_mono="$7" + ts_wall="$8" + boot_session_id="$9" + platform_id="${10}" + build_id="${11}" + + printf '{"seq":%s,"subsystem":"%s","current_state":"%s","requested_state":"%s","source":"%s","context":"%s","ts_monotonic":"%s","ts_wall":"%s","boot_session_id":"%s","platform":"%s","build":"%s"}' \ + "$seq" \ + "$(trace_escape_json "$subsystem")" \ + "$(trace_escape_json "$current_state")" \ + "$(trace_escape_json "$requested_state")" \ + "$(trace_escape_json "$source_ref")" \ + "$(trace_escape_json "$context")" \ + "$ts_mono" \ + "$ts_wall" \ + "$boot_session_id" \ + "$platform_id" \ + "$build_id" +} + +trace_build_summary_line() { + ts_wall="$1" + subsystem="$2" + current_state="$3" + requested_state="$4" + source_ref="$5" + context="$6" + + printf '%s | %s current=%s requested=%s source=%s context=%s' \ + "$ts_wall" "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context" +} + +# --------------------------------------------------------------------------- +# FSM — per-subsystem state machine checks +# --------------------------------------------------------------------------- + +# Return the path of the persisted last-state file for a subsystem. +trace_fsm_state_file() { + printf '%s/%s.state\n' "$TRACE_FSM_DIR" "$1" +} + +# Read the last known resulting state for a subsystem (empty string if unknown). +trace_fsm_get_last_state() { + _fsm_file="$(trace_fsm_state_file "$1")" + if [ -r "$_fsm_file" ]; then + cat "$_fsm_file" 2>/dev/null + fi +} + +# Persist the new resulting state for a subsystem. +trace_fsm_set_last_state() { + _fsm_file="$(trace_fsm_state_file "$1")" + mkdir -p "$TRACE_FSM_DIR" 2>/dev/null + printf '%s\n' "$2" > "$_fsm_file" +} + +# Return 0 if from_state → to_state is a valid transition for subsystem. +# UNKNOWN on either side of the arrow is always accepted (insufficient info). +trace_fsm_valid_transition() { + _fsm_sub="$1" + _fsm_from="$2" + _fsm_to="$3" + + # Can't validate if either side is unknown / empty + case "$_fsm_from" in ''|UNKNOWN) return 0 ;; esac + case "$_fsm_to" in ''|UNKNOWN) return 0 ;; esac + + case "$_fsm_sub" in + power) + case "$_fsm_from" in + BOOTING) + case "$_fsm_to" in RUNNING) return 0 ;; esac ;; + RUNNING) + case "$_fsm_to" in SLEEP|OFF|REBOOT|LOW_BATTERY) return 0 ;; esac ;; + SLEEP) + case "$_fsm_to" in RUNNING|OFF) return 0 ;; esac ;; + LOW_BATTERY) + case "$_fsm_to" in RUNNING|OFF) return 0 ;; esac ;; + OFF|REBOOT) + # terminal — nothing valid onward + return 1 ;; + *) + # unrecognised state: allow to avoid false positives + return 0 ;; + esac + return 1 + ;; + networking) + case "$_fsm_from" in + DISABLED) + case "$_fsm_to" in ENABLED) return 0 ;; esac ;; + ENABLED) + case "$_fsm_to" in DISABLED|CONNECTED) return 0 ;; esac ;; + CONNECTED) + case "$_fsm_to" in DISABLED|ENABLED) return 0 ;; esac ;; + *) + return 0 ;; + esac + return 1 + ;; + audio) + # Any VOL_N → VOL_M transition is valid + case "$_fsm_to" in VOL_*) return 0 ;; esac + return 1 + ;; + brightness) + # Any BL_N → BL_M transition is valid + case "$_fsm_to" in BL_*) return 0 ;; esac + return 1 + ;; + *) + # Unknown subsystem — don't flag it + return 0 + ;; + esac +} + +# Emit a dedicated inconsistency event into the same subsystem files. +# This is fire-and-forget; errors are suppressed so callers are never blocked. +trace_fsm_emit_inconsistency() { + _incon_sub="$1" + _incon_reason="$2" + _incon_claimed_current="$3" + _incon_requested="$4" + _incon_source="$5" + _incon_orig_context="$6" + + _incon_seq="$(trace_next_seq)" + _incon_ts_mono="$(trace_monotonic_ts)" + _incon_ts_wall="$(trace_wall_ts)" + _incon_boot="$(trace_boot_id)" + _incon_plat="${PLATFORM:-unknown}" + _incon_build="$(trace_build)" + + _incon_context="FSM_INCONSISTENCY reason=${_incon_reason} claimed_current=${_incon_claimed_current} requested=${_incon_requested} orig_source=${_incon_source} orig_context=${_incon_orig_context}" + + _incon_json="$(trace_build_json_line \ + "$_incon_seq" "$_incon_sub" "INCONSISTENT" "INCONSISTENT" \ + "trace_fsm" \ + "$(trace_escape_json "$_incon_context")" \ + "$_incon_ts_mono" "$_incon_ts_wall" \ + "$_incon_boot" "$_incon_plat" "$_incon_build")" + + _incon_summary="$(trace_build_summary_line \ + "$_incon_ts_wall" "$_incon_sub" "INCONSISTENT" "INCONSISTENT" \ + "trace_fsm" "$_incon_context")" + + trace_emit_core \ + "$TRACE_EVENTS_FILE" "$TRACE_SUMMARY_FILE" \ + "$TRACE_MAX_EVENTS" "$TRACE_MAX_SUMMARY_LINES" \ + "$_incon_json" "$_incon_summary" 2>/dev/null || true + trace_emit_core \ + "$(trace_subsystem_events_file "$_incon_sub")" \ + "$(trace_subsystem_summary_file "$_incon_sub")" \ + "$TRACE_MAX_EVENTS" "$TRACE_MAX_SUMMARY_LINES" \ + "$_incon_json" "$_incon_summary" 2>/dev/null || true +} + +# Run both FSM checks and emit an inconsistency event if either fails. +# Never returns non-zero — the caller's execution must not be affected. +trace_fsm_check() { + _fsmck_sub="$1" + _fsmck_current="$2" + _fsmck_requested="$3" + _fsmck_source="$4" + _fsmck_context="$5" + + # Check 1: continuity — does claimed current_state match last recorded state? + _fsmck_last="$(trace_fsm_get_last_state "$_fsmck_sub")" + if [ -n "$_fsmck_last" ] && \ + [ "$_fsmck_last" != "UNKNOWN" ] && \ + [ "$_fsmck_current" != "UNKNOWN" ] && \ + [ "$_fsmck_current" != "$_fsmck_last" ]; then + trace_fsm_emit_inconsistency \ + "$_fsmck_sub" \ + "continuity:expected=${_fsmck_last}" \ + "$_fsmck_current" "$_fsmck_requested" \ + "$_fsmck_source" "$_fsmck_context" || true + fi + + # Check 2: validity — is current_state → requested_state in the allowed set? + if ! trace_fsm_valid_transition "$_fsmck_sub" "$_fsmck_current" "$_fsmck_requested"; then + trace_fsm_emit_inconsistency \ + "$_fsmck_sub" \ + "invalid_transition:${_fsmck_current}->${_fsmck_requested}" \ + "$_fsmck_current" "$_fsmck_requested" \ + "$_fsmck_source" "$_fsmck_context" || true + fi + + # Check 3: large ordinal jump (audio and brightness only) + case "$_fsmck_sub" in + audio) + trace_fsm_check_level_jump \ + "$_fsmck_sub" "$_fsmck_current" "$_fsmck_requested" \ + "$_fsmck_source" "$_fsmck_context" \ + "$AUDIO_LARGE_JUMP_THRESHOLD" || true + ;; + brightness) + trace_fsm_check_level_jump \ + "$_fsmck_sub" "$_fsmck_current" "$_fsmck_requested" \ + "$_fsmck_source" "$_fsmck_context" \ + "$BRIGHTNESS_LARGE_JUMP_THRESHOLD" || true + ;; + esac + + return 0 +} + +# Emit a lifecycle marker (boot/shutdown boundary) to the main trace files +# and to a dedicated lifecycle log for easy session-boundary reconstruction. +# Never returns non-zero. +trace_fsm_emit_lifecycle() { + _lc_event="$1" # e.g. FSM_INIT, FSM_FINALIZE, INCONSISTENT_START, INCONSISTENT_END + _lc_context="$2" + _lc_sub="${3:-power}" + + _lc_seq="$(trace_next_seq)" + _lc_ts_mono="$(trace_monotonic_ts)" + _lc_ts_wall="$(trace_wall_ts)" + _lc_boot="$(trace_boot_id)" + _lc_plat="${PLATFORM:-unknown}" + _lc_build="$(trace_build)" + + _lc_json="$(trace_build_json_line \ + "$_lc_seq" "$_lc_sub" "$_lc_event" "$_lc_event" \ + "trace_fsm" \ + "$(trace_escape_json "$_lc_context")" \ + "$_lc_ts_mono" "$_lc_ts_wall" \ + "$_lc_boot" "$_lc_plat" "$_lc_build")" + _lc_summary="$(trace_build_summary_line \ + "$_lc_ts_wall" "$_lc_sub" "$_lc_event" "$_lc_event" \ + "trace_fsm" "$_lc_context")" + + trace_ensure_dirs + mkdir -p "$TRACE_FSM_DIR" 2>/dev/null + + trace_emit_core \ + "$TRACE_EVENTS_FILE" "$TRACE_SUMMARY_FILE" \ + "$TRACE_MAX_EVENTS" "$TRACE_MAX_SUMMARY_LINES" \ + "$_lc_json" "$_lc_summary" 2>/dev/null || true + trace_emit_core \ + "$(trace_subsystem_events_file "$_lc_sub")" \ + "$(trace_subsystem_summary_file "$_lc_sub")" \ + "$TRACE_MAX_EVENTS" "$TRACE_MAX_SUMMARY_LINES" \ + "$_lc_json" "$_lc_summary" 2>/dev/null || true + # dedicated lifecycle file — one line per session boundary, kept small + printf '%s\n' "$_lc_summary" >> "$TRACE_FSM_DIR/lifecycle.txt" 2>/dev/null || true +} + +# Called once during system startup (runtime.sh). +# 1. Inspects the persisted power state from the previous session: +# - If it is not OFF/REBOOT/empty, the previous session ended uncleanly; +# emit INCONSISTENT_END to record that. +# 2. Clears all FSM state files so the new session starts fresh. +# 3. Seeds power state as BOOTING and emits BOOTING→RUNNING + FSM_INIT. +# Never returns non-zero. +trace_fsm_boot_init() { + _bi_source="${1:-runtime.sh}" + + trace_ensure_dirs + mkdir -p "$TRACE_FSM_DIR" 2>/dev/null + + # ----------------------------------------------------------------------- + # TRACE_INITIALIZE — fires once, on the very first boot or after a full + # trace wipe. Detected by the absence of both: + # 1. any persisted FSM state file (no prior session), AND + # 2. any existing trace events file (no prior events at all). + # Emitted to all subsystems before any other lifecycle event so it + # appears as the first entry in every subsystem's trace log. + # ----------------------------------------------------------------------- + _bi_any_state="$(ls "$TRACE_FSM_DIR"/*.state 2>/dev/null | head -n1)" + if [ -z "$_bi_any_state" ] && [ ! -s "$TRACE_EVENTS_FILE" ]; then + for _bi_init_sub in power networking audio brightness; do + trace_fsm_emit_lifecycle \ + "TRACE_INITIALIZE" \ + "first trace session source=${_bi_source}" \ + "$_bi_init_sub" || true + done + fi + + # ----------------------------------------------------------------------- + # Check previous session end-state for each subsystem that has a defined + # terminal state, before wiping the state files. + # ----------------------------------------------------------------------- + + # power: must have ended in OFF or REBOOT + _bi_prev_power="$(trace_fsm_get_last_state power)" + case "${_bi_prev_power:-}" in + ''|OFF|REBOOT) + ;; # clean end or first-ever boot + *) + trace_fsm_emit_lifecycle \ + "INCONSISTENT_END" \ + "previous session ended without OFF/REBOOT; last_state=${_bi_prev_power}" \ + "power" || true + ;; + esac + + # networking: must have ended in DISABLED (WiFi torn down during shutdown) + _bi_prev_net="$(trace_fsm_get_last_state networking)" + case "${_bi_prev_net:-}" in + ''|DISABLED) + ;; # expected or first-ever boot + *) + trace_fsm_emit_lifecycle \ + "INCONSISTENT_END" \ + "previous session ended without DISABLED; last_state=${_bi_prev_net}" \ + "networking" || true + ;; + esac + + # audio: no required terminal state — emit INCONSISTENT_START if last + # recorded state is entirely absent after a non-first boot (power was + # previously recorded, i.e. this isn't the very first ever run). + # For audio and brightness we only flag a gap, not a wrong terminal state. + _bi_prev_audio="$(trace_fsm_get_last_state audio)" + if [ -n "${_bi_prev_power:-}" ] && [ -z "${_bi_prev_audio:-}" ]; then + trace_fsm_emit_lifecycle \ + "INCONSISTENT_START" \ + "no audio state persisted from previous session" \ + "audio" || true + fi + + _bi_prev_brightness="$(trace_fsm_get_last_state brightness)" + if [ -n "${_bi_prev_power:-}" ] && [ -z "${_bi_prev_brightness:-}" ]; then + trace_fsm_emit_lifecycle \ + "INCONSISTENT_START" \ + "no brightness state persisted from previous session" \ + "brightness" || true + fi + + # ----------------------------------------------------------------------- + # Reset all subsystem state files — fresh session + # ----------------------------------------------------------------------- + rm -f "$TRACE_FSM_DIR"/*.state 2>/dev/null || true + + # ----------------------------------------------------------------------- + # Seed power FSM: BOOTING → RUNNING (runs through normal FSM path) + # ----------------------------------------------------------------------- + trace_fsm_set_last_state "power" "BOOTING" || true + trace_write_system_emit "power" "BOOTING" "RUNNING" "$_bi_source" "system startup" || true + + # ----------------------------------------------------------------------- + # Emit FSM_INIT lifecycle marker for every subsystem + # ----------------------------------------------------------------------- + for _bi_sub in power networking audio brightness; do + trace_fsm_emit_lifecycle \ + "FSM_INIT" \ + "boot session started source=${_bi_source}" \ + "$_bi_sub" || true + done + + return 0 +} + +# Called once during shutdown (save_poweroff.sh), after the power-state emit +# and before stage 2 takes over. +# 1. Validates that the power FSM is now in OFF or REBOOT (i.e. the emit +# actually happened). If not, records INCONSISTENT_END. +# 2. Writes FSM_FINALIZE to close the session cleanly. +# Never returns non-zero. +trace_fsm_shutdown_finalize() { + _sf_source="${1:-save_poweroff.sh}" + + # ----------------------------------------------------------------------- + # Validate terminal states for subsystems that require them + # ----------------------------------------------------------------------- + + # power: must be OFF or REBOOT + _sf_power="$(trace_fsm_get_last_state power)" + case "${_sf_power:-}" in + OFF|REBOOT) + ;; # expected + *) + trace_fsm_emit_lifecycle \ + "INCONSISTENT_END" \ + "shutdown finalised without OFF/REBOOT; last_state=${_sf_power}" \ + "power" || true + ;; + esac + + # networking: must be DISABLED (torn down before unmount) + _sf_net="$(trace_fsm_get_last_state networking)" + case "${_sf_net:-}" in + ''|DISABLED) + ;; # expected or never emitted + *) + trace_fsm_emit_lifecycle \ + "INCONSISTENT_END" \ + "shutdown finalised without DISABLED; last_state=${_sf_net}" \ + "networking" || true + ;; + esac + + # audio: no required terminal state — absence of any recorded state + # after a session that did reach RUNNING is worth flagging + _sf_audio="$(trace_fsm_get_last_state audio)" + if [ "${_sf_power:-}" = "OFF" ] || [ "${_sf_power:-}" = "REBOOT" ]; then + if [ -z "${_sf_audio:-}" ]; then + trace_fsm_emit_lifecycle \ + "INCONSISTENT_END" \ + "no audio state recorded this session" \ + "audio" || true + fi + + _sf_brightness="$(trace_fsm_get_last_state brightness)" + if [ -z "${_sf_brightness:-}" ]; then + trace_fsm_emit_lifecycle \ + "INCONSISTENT_END" \ + "no brightness state recorded this session" \ + "brightness" || true + fi + fi + + # ----------------------------------------------------------------------- + # FSM_FINALIZE lifecycle marker for every subsystem + # ----------------------------------------------------------------------- + for _sf_sub in power networking audio brightness; do + trace_fsm_emit_lifecycle \ + "FSM_FINALIZE" \ + "shutdown sequence completed source=${_sf_source}" \ + "$_sf_sub" || true + done + + return 0 +} + +# Extract the trailing integer from a state name such as VOL_12 or BL_3. +# Prints the number, or nothing if the state has no numeric suffix. +trace_fsm_extract_level() { + printf '%s\n' "$1" | sed 's/^[^_]*_//; /^[0-9][0-9]*$/!d' +} + +# Check whether the transition from->to represents a large jump for ordinal +# subsystems (audio, brightness). Emits an inconsistency event if the +# absolute delta exceeds the configured threshold. Never returns non-zero. +trace_fsm_check_level_jump() { + _lj_sub="$1" + _lj_from="$2" + _lj_to="$3" + _lj_source="$4" + _lj_context="$5" + _lj_threshold="$6" + + # Threshold of 0 means the check is disabled + case "${_lj_threshold:-0}" in + ''|0|*[!0-9]*) return 0 ;; + esac + + _lj_from_n="$(trace_fsm_extract_level "$_lj_from")" + _lj_to_n="$(trace_fsm_extract_level "$_lj_to")" + + # Only meaningful when both states carry a numeric level + [ -n "$_lj_from_n" ] && [ -n "$_lj_to_n" ] || return 0 + + _lj_delta=$(( _lj_to_n - _lj_from_n )) + [ "$_lj_delta" -lt 0 ] && _lj_delta=$(( -_lj_delta )) + + if [ "$_lj_delta" -gt "$_lj_threshold" ]; then + trace_fsm_emit_inconsistency \ + "$_lj_sub" \ + "large_jump:delta=${_lj_delta},threshold=${_lj_threshold},from=${_lj_from},to=${_lj_to}" \ + "$_lj_from" "$_lj_to" \ + "$_lj_source" "$_lj_context" || true + fi + + return 0 +} + +# --------------------------------------------------------------------------- + +trace_write_system_emit() { + subsystem="$(trace_normalize_subsystem "$1")" + current_state="${2:-UNKNOWN}" + requested_state="${3:-$current_state}" + source_ref="${4:-unknown}" + context="${5:-}" + + [ -n "$current_state" ] || current_state="UNKNOWN" + [ -n "$requested_state" ] || requested_state="$current_state" + [ -n "$source_ref" ] || source_ref="unknown" + + trace_gate_enabled "$subsystem" || return 0 + + # FSM check: run before the normal emit so any inconsistency event gets a + # lower sequence number and appears just before the transition in the log. + trace_fsm_check "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context" || true + + trace_next_seq >/dev/null + seq="$trace_seq" + ts_mono="$(trace_monotonic_ts)" + ts_wall="$(trace_wall_ts)" + boot_session_id="$(trace_boot_id)" + platform_id="${PLATFORM:-unknown}" + build_id="$(trace_build)" + + json_line="$(trace_build_json_line "$seq" "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context" "$ts_mono" "$ts_wall" "$boot_session_id" "$platform_id" "$build_id")" + summary_line="$(trace_build_summary_line "$ts_wall" "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context")" + + trace_emit_core "$TRACE_EVENTS_FILE" "$TRACE_SUMMARY_FILE" "$TRACE_MAX_EVENTS" "$TRACE_MAX_SUMMARY_LINES" "$json_line" "$summary_line" + trace_emit_core "$(trace_subsystem_events_file "$subsystem")" "$(trace_subsystem_summary_file "$subsystem")" "$TRACE_MAX_EVENTS" "$TRACE_MAX_SUMMARY_LINES" "$json_line" "$summary_line" + + # Persist the new state so the next emit can check continuity. + trace_fsm_set_last_state "$subsystem" "$requested_state" || true + trace_cache_write_state "$subsystem" "$requested_state" || true +} + +system_emit() { + [ "$#" -ge 4 ] || return 1 + + subsystem="$(trace_normalize_subsystem "$1")" + current_state="${2:-UNKNOWN}" + requested_state="${3:-$current_state}" + source_ref="${4:-unknown}" + shift 4 + context="$*" + + trace_write_system_emit "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context" +} + +trace_format_level_state() { + prefix="$1" + raw_value="$2" + fallback="${3:-UNKNOWN}" + + case "$raw_value" in + ''|UNKNOWN|AUTO) + printf '%s\n' "$fallback" + ;; + "${prefix}"_*) + printf '%s\n' "$raw_value" + ;; + *[!0-9]*) + printf '%s\n' "$fallback" + ;; + *) + printf '%s_%s\n' "$prefix" "$raw_value" + ;; + esac +} + +trace_is_uint() { + case "$1" in + ''|*[!0-9]*) + return 1 + ;; + *) + return 0 + ;; + esac +} + +trace_emit_cached_or_unknown() { + [ "$#" -ge 3 ] || return 1 + + subsystem="$(trace_normalize_subsystem "$1")" + source_ref="$2" + shift 2 + context="$*" + + cached_state="$(trace_cache_read_state "$subsystem")" + case "$cached_state" in + '') + current_state="UNKNOWN" + requested_state="UNKNOWN" + ;; + *) + current_state="$cached_state" + requested_state="$cached_state" + ;; + esac + + system_emit "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context" +} + +trace_emit_from_current_to_cached_or_unknown() { + [ "$#" -ge 4 ] || return 1 + + subsystem="$(trace_normalize_subsystem "$1")" + current_state="${2:-UNKNOWN}" + source_ref="$3" + shift 3 + context="$*" + + cached_state="$(trace_cache_read_state "$subsystem")" + case "$cached_state" in + '') + requested_state="UNKNOWN" + ;; + *) + requested_state="$cached_state" + ;; + esac + + system_emit "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context" +} + +power_trace_emit() { + if [ "$#" -eq 4 ]; then + system_emit "power" "$1" "$2" "$3" "$4" + return + fi + + event="$1" + prev_state="${2:-UNKNOWN}" + intended_state="${3:-$prev_state}" + observed_state="${4:-$prev_state}" + source_ref="${6:-power_trace_emit}" + shift 6 2>/dev/null || true + + case "$observed_state" in + ''|AUTO) current_state="$prev_state" ;; + *) current_state="$observed_state" ;; + esac + case "$current_state" in + ''|AUTO) current_state="UNKNOWN" ;; + esac + case "$intended_state" in + ''|AUTO) requested_state="$current_state" ;; + *) requested_state="$intended_state" ;; + esac + + context="$event" + for extra in "$@"; do + [ -n "$extra" ] || continue + context="$context $extra" + done + + system_emit "power" "$current_state" "$requested_state" "$source_ref" "$context" +} + +power_trace_emit_shutdown_request() { + shutdown_mode="${1:-}" + source_ref="${2:-save_poweroff.sh}" + shift 2 + context="$*" + + case "$shutdown_mode" in + --reboot|REBOOT|reboot) + requested_state="REBOOT" + ;; + *) + requested_state="OFF" + ;; + esac + + current_state="$(trace_fsm_get_last_state "power" 2>/dev/null)" + case "${current_state:-}" in + RUNNING|SLEEP|LOW_BATTERY) ;; + *) current_state="RUNNING" ;; + esac + + system_emit "power" "$current_state" "$requested_state" "$source_ref" "$context" +} + +audio_trace_emit() { + [ "$#" -eq 4 ] || return 1 + system_emit "audio" "$1" "$2" "$3" "$4" +} + +audio_trace_emit_level() { + [ "$#" -ge 2 ] || return 1 + + requested_state="$(trace_format_level_state "VOL" "$1" "UNKNOWN")" + source_ref="$2" + shift 2 + context="$*" + + audio_trace_emit "UNKNOWN" "$requested_state" "$source_ref" "$context" +} + +audio_trace_emit_levels() { + [ "$#" -ge 3 ] || return 1 + + current_state="$(trace_format_level_state "VOL" "$1" "UNKNOWN")" + requested_state="$(trace_format_level_state "VOL" "$2" "$current_state")" + source_ref="$3" + shift 3 + context="$*" + + audio_trace_emit "$current_state" "$requested_state" "$source_ref" "$context" +} + +audio_trace_emit_cached_or_unknown() { + [ "$#" -ge 1 ] || return 1 + + source_ref="$1" + shift + context="$*" + trace_emit_cached_or_unknown "audio" "$source_ref" "$context" +} + +audio_trace_emit_from_current_to_cached_or_unknown() { + [ "$#" -ge 2 ] || return 1 + + current_state="$(trace_format_level_state "VOL" "$1" "UNKNOWN")" + source_ref="$2" + shift 2 + context="$*" + trace_emit_from_current_to_cached_or_unknown "audio" "$current_state" "$source_ref" "$context" +} + +audio_trace_emit_startup_baseline_if_missing() { + source_ref="${1:-runtimeHelper.sh}" + shift + context="$*" + [ -n "$context" ] || context="startup volume baseline cached or unavailable" + + startup_audio_last="$(trace_fsm_get_last_state "audio" 2>/dev/null)" + [ -n "$startup_audio_last" ] || audio_trace_emit_cached_or_unknown "$source_ref" "$context" +} + +audio_trace_emit_shutdown_baseline_if_missing() { + source_ref="${1:-save_poweroff.sh}" + shift + context="$*" + [ -n "$context" ] || context="shutdown fallback volume baseline cached or unavailable" + + shutdown_audio_last="$(trace_fsm_get_last_state "audio" 2>/dev/null)" + [ -n "$shutdown_audio_last" ] || audio_trace_emit_cached_or_unknown "$source_ref" "$context" +} + +audio_trace_emit_wake_restore() { + [ "$#" -ge 3 ] || return 1 + + current_raw="$1" + restore_raw="$2" + source_ref="$3" + shift 3 + context="$*" + + current_state="$(trace_format_level_state "VOL" "$current_raw" "UNKNOWN")" + if trace_is_uint "$restore_raw"; then + restore_context="$context" + [ -n "$restore_context" ] || restore_context="volume restored on wake" + requested_state="$(trace_format_level_state "VOL" "$restore_raw" "$current_state")" + audio_trace_emit "$current_state" "$requested_state" "$source_ref" "$restore_context" + else + fallback_context="$context" + [ -n "$fallback_context" ] || fallback_context="volume restore cached or unavailable on wake" + trace_emit_from_current_to_cached_or_unknown "audio" "$current_state" "$source_ref" "$fallback_context" + fi +} + +network_trace_emit() { + [ "$#" -eq 4 ] || return 1 + system_emit "networking" "$1" "$2" "$3" "$4" +} + +brightness_trace_emit() { + [ "$#" -eq 4 ] || return 1 + system_emit "brightness" "$1" "$2" "$3" "$4" +} + +brightness_trace_emit_level() { + [ "$#" -ge 2 ] || return 1 + + requested_state="$(trace_format_level_state "BL" "$1" "UNKNOWN")" + source_ref="$2" + shift 2 + context="$*" + + brightness_trace_emit "UNKNOWN" "$requested_state" "$source_ref" "$context" +} + +brightness_trace_emit_levels() { + [ "$#" -ge 3 ] || return 1 + + current_state="$(trace_format_level_state "BL" "$1" "UNKNOWN")" + requested_state="$(trace_format_level_state "BL" "$2" "$current_state")" + source_ref="$3" + shift 3 + context="$*" + + brightness_trace_emit "$current_state" "$requested_state" "$source_ref" "$context" +} + +brightness_trace_emit_cached_or_unknown() { + [ "$#" -ge 1 ] || return 1 + + source_ref="$1" + shift + context="$*" + trace_emit_cached_or_unknown "brightness" "$source_ref" "$context" +} + +brightness_trace_emit_startup_baseline_if_missing() { + source_ref="${1:-runtimeHelper.sh}" + shift + context="$*" + [ -n "$context" ] || context="startup brightness baseline cached or unavailable" + + startup_bl_last="$(trace_fsm_get_last_state "brightness" 2>/dev/null)" + [ -n "$startup_bl_last" ] || brightness_trace_emit_cached_or_unknown "$source_ref" "$context" +} + +brightness_trace_emit_shutdown_baseline_if_missing() { + source_ref="${1:-save_poweroff.sh}" + shift + context="$*" + [ -n "$context" ] || context="shutdown fallback brightness baseline cached or unavailable" + + shutdown_bl_last="$(trace_fsm_get_last_state "brightness" 2>/dev/null)" + [ -n "$shutdown_bl_last" ] || brightness_trace_emit_cached_or_unknown "$source_ref" "$context" +} + +brightness_trace_emit_wake_baseline() { + [ "$#" -ge 2 ] || return 1 + + wake_raw="$1" + source_ref="$2" + shift 2 + context="$*" + + if trace_is_uint "$wake_raw"; then + wake_context="$context" + [ -n "$wake_context" ] || wake_context="brightness baseline on wake" + wake_state="$(trace_format_level_state "BL" "$wake_raw" "UNKNOWN")" + brightness_trace_emit "$wake_state" "$wake_state" "$source_ref" "$wake_context" + else + fallback_context="$context" + [ -n "$fallback_context" ] || fallback_context="brightness baseline cached or unavailable on wake" + brightness_trace_emit_cached_or_unknown "$source_ref" "$fallback_context" + fi +} + +av_trace_emit_startup_baselines_if_missing() { + source_ref="${1:-runtimeHelper.sh}" + audio_trace_emit_startup_baseline_if_missing "$source_ref" || true + brightness_trace_emit_startup_baseline_if_missing "$source_ref" || true +} + +av_trace_emit_shutdown_baselines_if_missing() { + source_ref="${1:-save_poweroff.sh}" + audio_trace_emit_shutdown_baseline_if_missing "$source_ref" || true + brightness_trace_emit_shutdown_baseline_if_missing "$source_ref" || true +} + +trace_process_lane_id() { + lane="$(printf '%s' "${1:-}" | tr '[:upper:]' '[:lower:]' | tr -c 'a-z0-9_-' '-')" + case "$lane" in + ''|-) lane="unknown" ;; + archiveunpacker) lane="archiveunpacker" ;; + firstboot) lane="firstboot" ;; + esac + printf '%s\n' "$lane" +} + +process_trace_subsystem() { + lane_id="$(trace_process_lane_id "$1")" + printf '%s\n' "process-${lane_id}" +} + +process_trace_init() { + [ "$#" -ge 2 ] || return 1 + + lane_id="$(trace_process_lane_id "$1")" + source_ref="${2:-unknown}" + shift 2 + context="$*" + + subsystem="$(process_trace_subsystem "$lane_id")" + last_state="$(trace_fsm_get_last_state "$subsystem")" + [ -n "$last_state" ] || last_state="UNKNOWN" + + case "$last_state" in + UNKNOWN|FINALIZED|COMPLETE|FAILED|HANDOFF_BACKGROUND|SKIPPED_LOCK) + ;; + *) + trace_fsm_emit_inconsistency \ + "$subsystem" \ + "init_without_finalize:last_state=${last_state}" \ + "$last_state" "RUNNING" \ + "$source_ref" "$context" || true + ;; + esac + + system_emit "$subsystem" "$last_state" "RUNNING" "$source_ref" "FSM_INIT lane=${lane_id} ${context}" +} + +process_trace_finalize() { + [ "$#" -ge 2 ] || return 1 + + lane_id="$(trace_process_lane_id "$1")" + source_ref="${2:-unknown}" + if [ "$#" -ge 3 ]; then + final_state="${3:-FINALIZED}" + shift 3 + else + final_state="FINALIZED" + shift 2 + fi + context="$*" + + subsystem="$(process_trace_subsystem "$lane_id")" + current_state="$(trace_fsm_get_last_state "$subsystem")" + [ -n "$current_state" ] || current_state="UNKNOWN" + + case "$final_state" in + ''|AUTO) + final_state="FINALIZED" + ;; + esac + + if [ "$current_state" = "UNKNOWN" ]; then + trace_fsm_emit_inconsistency \ + "$subsystem" \ + "finalize_without_init" \ + "$current_state" "$final_state" \ + "$source_ref" "$context" || true + fi + + system_emit "$subsystem" "$current_state" "$final_state" "$source_ref" "FSM_FINALIZE lane=${lane_id} ${context}" +} + +process_trace_emit() { + [ "$#" -ge 3 ] || return 1 + + lane_id="$(trace_process_lane_id "$1")" + requested_state="${2:-UNKNOWN}" + source_ref="${3:-unknown}" + shift 3 + context="$*" + + subsystem="$(process_trace_subsystem "$lane_id")" + current_state="$(trace_cache_read_state "$subsystem")" + [ -n "$current_state" ] || current_state="UNKNOWN" + + case "$requested_state" in + ''|AUTO) requested_state="$current_state" ;; + esac + + system_emit "$subsystem" "$current_state" "$requested_state" "$source_ref" "$context" +}