Add power-mode and observability hooks

spruce/scripts/firstboot.sh

@@ -2,35 +2,81 @@
 
 . /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
     log_message "Preparing SSH keys if necessary"
     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

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,19 +672,22 @@ 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
 
     # 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 <section>"
 
     if [ -z "$UPDATE_FILE" ] || [ -z "$DEST_DIR" ] || [ -z "$LOG_LOCATION" ]; then
-        echo "Usage: extract_7z_with_progress <archive.7z> <destination> <log_file> [display_label]"
+        echo "Usage: extract_7z_with_progress <archive.7z> <destination> <log_file> [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"
 }
-

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

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

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
-}
+}