From ceaec053b6e2945433e0d76e6ca109eadcb6159b Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:07:51 +0100 Subject: [PATCH 01/11] Describe exit statuses 1-3, 64 and 115 without filler 1-3 told the reader to look at the output; 64 and 115 described what the engine and scripts no longer use them for. --- api/exitcodes.func | 79 ++++++++-------------------------------------- 1 file changed, 13 insertions(+), 66 deletions(-) diff --git a/api/exitcodes.func b/api/exitcodes.func index ad83c87..5163f33 100644 --- a/api/exitcodes.func +++ b/api/exitcodes.func @@ -3,45 +3,25 @@ # License: MIT | https://raw.githubusercontent.com/community-scripts/core/main/LICENSE # ============================================================================== -# API/EXIT CODE EXPLANATIONS +# API/EXIT CODES # ============================================================================== -# Part of the telemetry layer. Load api/api.func -- it sources every part -- -# rather than this file directly; the split is for maintenance only and no -# function name or behaviour changed with it. -# -# Turns a numeric exit status into a sentence, and sorts it into a category -# for the telemetry field. Almost entirely a lookup table, and the authoritative -# copy of it. -# -# Two things have to move with it. core/error_handler.func carries a fallback -# table for the container case, where this file is not loaded; and the aborted -# branch of post_update_to_api has to agree with the user_aborted codes below, -# or a run is filed as one thing and described as another. The pointer here used -# to name docs/exit_codes.md, which does not exist. - +# Exit status -> description and telemetry category. Loaded through api/api.func +# on the host and by lxc/install.func inside the container. The abort codes in +# categorize_error must match post_update_to_api in api/telemetry.func. # ============================================================================== [[ -n "${_API_EXITCODES_LOADED:-}" ]] && return 0 _API_EXITCODES_LOADED=1 -# ------------------------------------------------------------------------------ -# explain_exit_code() -# -# - Maps numeric exit codes to human-readable error descriptions -# - Canonical source of truth for ALL exit code mappings -# - Used by both api.func (telemetry) and error_handler.func (error display) -# ------------------------------------------------------------------------------ +# explain_exit_code explain_exit_code() { local code="$1" case "$code" in # --- Generic / Shell --- - # Reached through the aborted branch of post_update_to_api: a clean exit that - # never reported success is someone backing out of a dialog. Every one of - # those records read "Unknown error". 0) echo "Cancelled before completion (no error)" ;; - 1) echo "The command failed; its output says why" ;; - 2) echo "The command failed with status 2 (a usage error for most tools); its output says why" ;; - 3) echo "The command failed with status 3; its output says why" ;; + 1) echo "General error" ;; + 2) echo "Invalid usage or arguments" ;; + 3) echo "Command-specific error" ;; 10) echo "Docker / privileged mode required (unsupported environment)" ;; # --- curl / wget errors --- @@ -103,7 +83,7 @@ explain_exit_code() { 112) echo "Proxmox: Invalid install menu option" ;; 113) echo "LXC: Under-provisioned — user aborted update" ;; 114) echo "LXC: Storage too low — user aborted update" ;; - 115) echo "Download: install.func download failed or incomplete" ;; + 115) echo "Engine or install script could not be downloaded" ;; 116) echo "Proxmox: Default bridge vmbr0 not found" ;; 117) echo "LXC: Container did not reach running state" ;; 118) echo "LXC: No IP assigned to container after timeout" ;; @@ -114,7 +94,7 @@ explain_exit_code() { 123) echo "LXC: Local IP detection failed" ;; # --- BSD sysexits.h (64-78) --- - 64) echo "Usage error (wrong arguments)" ;; + 64) echo "Missing or invalid input (a required setting was not given)" ;; 65) echo "Data format error (bad input data)" ;; 66) echo "Input file not found (cannot open input)" ;; 67) echo "User not found (addressee unknown)" ;; @@ -177,12 +157,6 @@ explain_exit_code() { 193) echo "MongoDB: Fatal query error" ;; # --- Engine (199) --- - # Not a failure of the install. It means the engine reported a terminal status - # without a code to go with it -- the flag file was unreadable, or a caller - # passed nothing. It used to be reported as 1, which is also what bash returns - # for any ordinary command failure, so a lost code and a real general error - # were the same number. - 199) echo "Engine: exit code not reported" ;; # --- Proxmox Custom Codes (200-231) --- @@ -200,11 +174,6 @@ explain_exit_code() { 213) echo "Proxmox: Storage type does not support 'rootdir' content" ;; 214) echo "Proxmox: Not enough storage space" ;; 215) echo "Proxmox: Container created but not listed (ghost state)" ;; - # 197 runs across 70 apps in a fortnight failed here and were filed as a - # package manager problem: pct returns 255, and 255 is DPKG's fatal error. A - # container that will not start is not a dependency problem, and calling it one - # sends everybody looking in the wrong place. - 227) echo "Proxmox: Container created but failed to start" ;; 216) echo "Proxmox: RootFS entry missing in config" ;; 217) echo "Proxmox: Storage not accessible" ;; 218) echo "Proxmox: Template file corrupted or incomplete" ;; @@ -216,6 +185,7 @@ explain_exit_code() { 224) echo "Proxmox: PBS storage is for backups only" ;; 225) echo "Proxmox: No template available for OS/Version" ;; 226) echo "Proxmox: VM disk import or post-creation setup failed" ;; + 227) echo "Proxmox: Container created but failed to start" ;; 228) echo "Proxmox: Cluster filesystem /etc/pve not available" ;; 231) echo "Proxmox: LXC stack too old for the template, or its upgrade failed" ;; @@ -252,19 +222,8 @@ explain_exit_code() { esac } -# ------------------------------------------------------------------------------ -# categorize_error() -# -# - Maps exit codes to error categories for dashboard grouping -# - Can be overridden via ERROR_CATEGORY_OVERRIDE (log-based subclassification) -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# categorize_error() -# -# - Maps exit codes to error categories for dashboard grouping -# - Can be overridden via ERROR_CATEGORY_OVERRIDE (log-based subclassification) -# ------------------------------------------------------------------------------ +# categorize_error [command] +# ERROR_CATEGORY_OVERRIDE wins; the tool that ran beats a code several tools share. categorize_error() { if [[ -n "${ERROR_CATEGORY_OVERRIDE:-}" ]]; then echo "$ERROR_CATEGORY_OVERRIDE" @@ -277,7 +236,6 @@ categorize_error() { 134 | 137) echo "resource"; return ;; 139 | 141) echo "signal"; return ;; esac - # The tool that ran says more than a status several tools share. if [[ -z "$command" ]] && declare -f _tm_find_errinfo >/dev/null 2>&1 && errinfo=$(_tm_find_errinfo); then command=$(sed -n 's/^COMMAND=//p' "$errinfo" | head -n1) fi @@ -304,14 +262,3 @@ categorize_error() { esac } -# ============================================================================== -# SECTION 2: JSON & LOG HELPERS -# ============================================================================== - -# ------------------------------------------------------------------------------ -# json_escape() -# -# - Escapes a string for safe JSON embedding -# - Strips ANSI escape sequences and non-printable control characters -# - Uses jq when available (guaranteed correct), falls back to awk -# ------------------------------------------------------------------------------ From fc6bc752d1f39d5e8433805fd1fb325e400c2bc0 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:08:26 +0100 Subject: [PATCH 02/11] Telemetry payload v3: the failing step, its message and its output error_message, error_step, error_phase and failed_function travel as their own fields. The trace holds the failing command's output or the failing step's log lines with package and download progress removed, and IPv4 anonymisation no longer eats version numbers. A helper's "return N" is replaced by the call that failed, and a silent() failure a helper passed up keeps its capture. Tool and add-on runs use the same payload. --- .github/workflows/verify-split-files.yml | 5 + api/API.txt | 9 +- api/api.func | 90 ++--- api/errorlog.func | 388 ++++++++------------ api/sysinfo.func | 52 +-- api/telemetry.func | 399 ++++----------------- core/core.func | 42 +-- core/error_handler.func | 434 +++++++++-------------- tests/exit-code-hints.sh | 28 +- tests/stale-silent-record.sh | 17 +- tests/telemetry-trace.sh | 127 +++++++ 11 files changed, 606 insertions(+), 985 deletions(-) create mode 100644 tests/telemetry-trace.sh diff --git a/.github/workflows/verify-split-files.yml b/.github/workflows/verify-split-files.yml index 021c45a..3fa8997 100644 --- a/.github/workflows/verify-split-files.yml +++ b/.github/workflows/verify-split-files.yml @@ -36,6 +36,7 @@ on: - "tests/failed-command-output.sh" - "tests/stale-silent-record.sh" - "tests/exit-code-hints.sh" + - "tests/telemetry-trace.sh" - "tests/forge-release-json.sh" - "tests/install-cleanup.sh" - "tests/console-hangup.sh" @@ -71,6 +72,7 @@ on: - "tests/failed-command-output.sh" - "tests/stale-silent-record.sh" - "tests/exit-code-hints.sh" + - "tests/telemetry-trace.sh" - "tests/forge-release-json.sh" - "tests/install-cleanup.sh" - "tests/console-hangup.sh" @@ -141,6 +143,9 @@ jobs: - name: Exit code hint tests run: bash tests/exit-code-hints.sh + - name: Telemetry trace tests + run: bash tests/telemetry-trace.sh + - name: Forge release lookup tests run: bash tests/forge-release-json.sh diff --git a/api/API.txt b/api/API.txt index 73fde43..8de3c7a 100644 --- a/api/API.txt +++ b/api/API.txt @@ -1,11 +1,17 @@ _telemetry_report_exit _tm_clean_log _tm_enabled +_tm_error_context _tm_explain _tm_find_errinfo +_tm_focus +_tm_format_error +_tm_one_line _tm_payload _tm_pick_logfile +_tm_post_run _tm_send +_tm_step_output build_error_string categorize_error detect_arm @@ -15,8 +21,6 @@ detect_ram detect_repo_source explain_exit_code get_error_log -get_error_text -get_full_log get_install_duration init_tool_telemetry json_escape @@ -29,4 +33,3 @@ post_update_to_api start_install_timer telemetry_collect_sysinfo telemetry_new_attempt -write_errinfo diff --git a/api/api.func b/api/api.func index c160e52..824c398 100644 --- a/api/api.func +++ b/api/api.func @@ -4,86 +4,34 @@ # License: MIT | https://raw.githubusercontent.com/community-scripts/ProxmoxVE/main/LICENSE # ============================================================================== -# API.FUNC - TELEMETRY & DIAGNOSTICS API (v3 - single-reporter rewrite) +# API.FUNC - TELEMETRY # ============================================================================== +# Anonymous install telemetry for telemetry.community-scripts.org. Opt-out via +# DIAGNOSTICS=no (/usr/local/community-scripts/diagnostics). # -# Provides functions for sending anonymous telemetry data via the community -# telemetry ingest service at telemetry.community-scripts.org. -# -# DESIGN PRINCIPLES (v3): -# 1. SINGLE REPORTER: only the HOST sends terminal statuses (success/failed/ -# aborted). Containers never curl the telemetry endpoint for terminal -# events - they write local artifact files (.failed flag + .errinfo) that -# the host picks up. This prevents the "first terminal event wins" race -# on the server from persisting a metadata-less container payload and -# discarding the full host payload. -# 2. FULL PAYLOAD, ALWAYS: every send includes the complete system metadata -# (os, pve version, arch, cpu, gpu, ram, repo attribution). No more -# minimal payloads that create empty records. -# 3. FOCUSED ERROR TRACE: the error field contains exactly the output of the -# command that failed (captured by silent() via byte offset), prefixed -# with "exit_code=N | | at line L: ". Not a 120KB -# log dump, not the wrong phase of the log. -# 4. IDEMPOTENT FINALIZE: post_update_to_api() sends exactly one terminal -# status per execution, no matter how many traps fire. -# -# Usage: -# source <(curl -fsSL .../api.func) -# post_to_api # Report LXC container creation ("installing") -# post_to_api_vm # Report VM creation ("installing") -# post_progress_to_api # Progress ping ("validation"/"configuring") -# post_update_to_api # Final status ("done"/"failed"/"aborted") -# -# Privacy: -# - Only anonymous statistics (no personal data, IPs are anonymized) -# - User can opt-out via DIAGNOSTICS=no -# - Random UUID for session tracking only +# Only the host sends a terminal status (success/failed/aborted), once per +# execution. A container leaves /root/.install-.failed and an +# .errinfo capture behind, which the host reads after the install returns. # +# exitcodes.func exit status -> description and category +# errorlog.func the failing step's output and the error trace +# sysinfo.func repo origin, CPU, GPU, RAM, architecture +# telemetry.func payload and senders # ============================================================================== -# ============================================================================== -# Telemetry Configuration -# ============================================================================== TELEMETRY_URL="${TELEMETRY_URL:-https://telemetry.community-scripts.org/telemetry}" - -# Timeout for progress pings (seconds) TELEMETRY_TIMEOUT=5 - -# Payload schema version, sent as a field and in the User-Agent. -# -# Bump it whenever the payload gains, loses or changes the meaning of a field, so -# the server can tell an old client from a new one. Before it existed the only -# way to guess a client's age was which fields happened to be present, which made -# every staged change a blind rollout. -# -# 1 the original payload -# 2 adds kernel_version, app_version, failed_command, failed_line; -# gpu_passthrough changes meaning from host capability to actual passthrough -TELEMETRY_PAYLOAD_VERSION=2 -# Timeout for final status updates (they carry the error trace) STATUS_TIMEOUT=10 -# Max size of the error trace sent to the API (bytes) and max line count. -# Keep this SMALL and FOCUSED - the goal is "exactly the messages from the -# moment of failure", not the whole installation log. +# Bump when a field is added, removed or changes meaning; sent as a field and in the User-Agent. +# 1 original payload +# 2 kernel_version, app_version, failed_command, failed_line; gpu_passthrough = actual passthrough +# 3 error_message, error_step, error_phase, failed_function; step-scoped, noise-filtered trace +TELEMETRY_PAYLOAD_VERSION=3 + TELEMETRY_ERROR_MAX_LINES=60 TELEMETRY_ERROR_MAX_BYTES=10240 -# ============================================================================== -# SECTION 0: REPOSITORY SOURCE DETECTION -# ============================================================================== - -# ============================================================================== -# The implementations live in api/. Splitting them was a maintenance -# change only -- every function kept its name, its body and its behaviour, and -# this file stays the single thing to source. -# -# exitcodes.func numeric status -> sentence and category -# errorlog.func finding, trimming and formatting the failing log -# sysinfo.func repo origin, GPU, CPU, RAM, architecture -# telemetry.func payload, transport and the senders -# ============================================================================== - # Repeated per file rather than shared: there is nowhere to put a shared copy # that does not itself need downloading first. See core/build.func. _CS_CURL_RETRY=(--retry 3 --retry-delay 1 --retry-connrefused --connect-timeout 10) @@ -96,7 +44,11 @@ _api_source_part() { return fi - # Inside a container there is no resolver: fall back to the engine base. + if [[ -n "${COMMUNITY_SCRIPTS_CORE_DIR:-}" && -s "${COMMUNITY_SCRIPTS_CORE_DIR}/api/${part}.func" ]]; then + # shellcheck disable=SC1090 + source "${COMMUNITY_SCRIPTS_CORE_DIR}/api/${part}.func" + return + fi local base="${COMMUNITY_SCRIPTS_CORE_URL:-https://raw.githubusercontent.com/community-scripts/core/main}" if command -v curl >/dev/null 2>&1; then # shellcheck disable=SC1090 diff --git a/api/errorlog.func b/api/errorlog.func index c894d3b..fc3cde6 100644 --- a/api/errorlog.func +++ b/api/errorlog.func @@ -5,25 +5,27 @@ # ============================================================================== # API/ERROR LOG EXTRACTION # ============================================================================== -# Part of the telemetry layer. Load api/api.func -- it sources every part -- -# rather than this file directly; the split is for maintenance only and no -# function name or behaviour changed with it. +# Turns a failure into the telemetry error trace: which capture belongs to it, +# what the failing step printed (progress chatter removed), and the one-line +# header. Loaded through api/api.func; host side only. # -# Finds the log that belongs to a failure, trims it to something sendable and -# builds the error string. Everything here is about producing text, not about -# sending it. +# The .errinfo capture, written by silent() and the error handler: +# +# EXIT_CODE= +# LINE= +# COMMAND= +# FUNCTION= +# STEP= +# MESSAGE= +# PHASE= +# --- OUTPUT --- +# # ============================================================================== [[ -n "${_API_ERRORLOG_LOADED:-}" ]] && return 0 _API_ERRORLOG_LOADED=1 -# ------------------------------------------------------------------------------ -# json_escape() -# -# - Escapes a string for safe JSON embedding -# - Strips ANSI escape sequences and non-printable control characters -# - Uses jq when available (guaranteed correct), falls back to awk -# ------------------------------------------------------------------------------ +# json_escape - JSON string body, control characters and ANSI removed json_escape() { local input input=$(printf '%s' "$1" | @@ -35,7 +37,6 @@ json_escape() { return fi - # Fallback: character-by-character processing with awk printf '%s' "$input" | awk ' BEGIN { ORS="" } @@ -51,40 +52,60 @@ json_escape() { }' } -# ------------------------------------------------------------------------------ -# _tm_clean_log() -# -# - stdin filter: strips ANSI/CR, anonymizes IPs (GDPR), drops pure -# progress-noise lines (apt/dpkg download and unpack chatter) -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# _tm_clean_log() -# -# - stdin filter: strips ANSI/CR, anonymizes IPs (GDPR), drops pure -# progress-noise lines (apt/dpkg download and unpack chatter) -# ------------------------------------------------------------------------------ +# Lines that never explain a failure. +_TM_NOISE=( + '(Get|Hit|Ign):[0-9]+ ' 'Fetched [0-9]' 'Reading (package lists|state information|database)' + 'Building dependency tree' '\(Reading database' 'Selecting previously unselected' 'Preparing to unpack' + 'Unpacking ' 'Setting up ' 'Processing triggers for' 'update-alternatives: ' 'Created symlink ' + "Removed ['\"]?/etc/systemd" 'Generating locales' 'Generation complete' 'Need to get [0-9]' 'After this operation' + '[0-9]+ upgraded, [0-9]+ newly installed' 'The following (NEW |additional )?packages will be' + 'Updating certificates in' 'Running hooks in' '[0-9]+ added, [0-9]+ removed; done' 'done\.$' + '(Summary|Installing|Upgrading):$' ' (Upgrading|Installing): [0-9]+, ' ' (Download size|Space needed): ' + 'debconf: (unable to initialize frontend|\(|falling back to frontend|delaying package configuration)' + 'invoke-rc\.d: (could not determine current runlevel|policy-rc\.d denied)' + 'Could not execute systemctl: +at /usr/bin/deb-systemd-invoke' 'rehash: warning: skipping' + 'Creating config file ' '(info: )?Adding (new )?(user|group|system user) ' 'info: (Selecting|Not creating|Creating home)' + '\([0-9]+/[0-9]+\) (Installing|Upgrading|Purging|Replacing) ' 'Executing [^ ]+\.(trigger|post-install|pre-install|post-upgrade)' + 'OK: [0-9.]+ ?[KMG]i?B in [0-9]+ packages' 'fetch https?://' + ' +(Installing|Upgrading|Verifying|Running scriptlet|Preparing|Cleanup|Downgrading|Erasing) *: ' + ' *[0-9]+K[ .]{10,}' 'Saving to: ' 'Length: [0-9]' 'Resolving [^ ]+ \(' 'Connecting to .*connected\.$' + 'HTTP request sent, awaiting response\.\.\. (20[0-9]|30[0-9])' 'Location: .*\[following\]' + ' *% Total +% Received' ' *[0-9]+ +[0-9.]+[kMG]? +[0-9]+ +[0-9.]+[kMG]? +[0-9]+ +[0-9]+ .*[0-9:-]{8}' + 'go: (downloading|finding|extracting) ' ' +(Compiling|Downloaded|Downloading|Fresh|Locking|Updating crates\.io index) ' + '(Collecting|Using cached|Requirement already satisfied|Installing collected packages) ' + ' *(Downloaded|Prepared|Installed|Resolved|Audited|Uninstalled|Built) [0-9]+ packages? ' ' [+-] [A-Za-z0-9_.-]+==' + 'Using C?Python [0-9]' 'Creating virtual environment at' 'npm (warn|WARN) deprecated' + '(added|removed|changed) [0-9]+ packages' '[0-9]+ packages? (is|are) looking for funding' ' run `npm fund`' + 'found 0 vulnerabilities' 'Progress: resolved [0-9]+' '\[[0-9]/[0-9]\] (Resolving|Fetching|Linking|Building)' + '(remote: )?(Enumerating|Counting|Compressing|Total) objects' 'Receiving objects:' 'Resolving deltas:' 'Updating files:' + '\++ ' + ' WARNING: (You have not turned on protection|Set activation/thin_pool|Sum of all thin volume)' + ' Logical volume .* (created|changed)\.' 'Creating filesystem with' 'Filesystem UUID:' 'Superblock backups stored' + '[[:space:]]+[0-9]+(, [0-9]+)+,?$' '(Allocating group tables|Writing inode tables|Creating journal|Writing superblocks|Discarding device blocks)' + 'extracting archive' 'Total bytes read:' 'Detected container architecture' 'Creating SSH host key' 'done: SHA256:' + '={20,}$' 'COMBINED INSTALLATION LOG' 'PHASE [0-9]+: ' '(Container ID|Session ID|Timestamp): ' + '[[:space:]]*(⏳|✔|✖|💡|ℹ|🔧|📋)' +) +_TM_NOISE_RE="^($(IFS='|'; echo "${_TM_NOISE[*]}"))" + +# stdin filter: ANSI and CR stripped, IPv4 anonymised, noise and blank lines dropped _tm_clean_log() { - sed 's/\r$//' | - sed 's/\x1b\[[0-9;]*[a-zA-Z]//g' | - sed -E 's/([0-9]{1,3}\.)[0-9]{1,3}\.[0-9]{1,3}/\1x.x/g' | - grep -avE '^(Get:|Hit:|Ign:|Fetched |Reading package lists|Reading state information|Building dependency tree|Selecting previously|Preparing to unpack|Unpacking |Processing triggers for|\(Reading database|[0-9]+%[[:space:]]*\[)' | - grep -avE '^[[:space:]]*$' || true + sed -E -e 's/\r$//' -e 's/\x1b\[[0-9;?]*[a-zA-Z]//g' \ + -e 's/\b([0-9]{1,3})\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\b/\1.x.x.x/g' | + grep -avE "$_TM_NOISE_RE" | grep -avE '^[[:space:]]*$' || true } -# ------------------------------------------------------------------------------ -# _tm_pick_logfile() -# -# - Returns the most specific available log file (combined → INSTALL_LOG → -# BUILD_LOG → SILENT_LOGFILE). Never downgrades a present log. -# ------------------------------------------------------------------------------ +# stdin filter: from the last [INFO] or [OK] log line on - the step that failed +_tm_step_output() { + awk '/^\[[0-9-]+ [0-9:]+\] \[(INFO|OK)\] /{n=0} {buf[n++]=$0} END{for(i=0;i/dev/null 2>&1; then - ensure_log_on_host 2>/dev/null || true - fi - - logfile=$(_tm_pick_logfile) - [[ -z "$logfile" || ! -s "$logfile" ]] && return 0 - - _tm_clean_log <"$logfile" | tail -n "$max_lines" -} - -# ------------------------------------------------------------------------------ -# get_error_text() (legacy compatibility) -# -# - Returns last 20 relevant lines of the active log -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# get_error_text() (legacy compatibility) -# -# - Returns last 20 relevant lines of the active log -# ------------------------------------------------------------------------------ -get_error_text() { - get_error_log 20 -} - -# ------------------------------------------------------------------------------ -# get_full_log() (legacy compatibility - dev/debug use only) -# -# - Returns the full log, ANSI-stripped and IP-anonymized, capped at max_bytes -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# get_full_log() (legacy compatibility - dev/debug use only) -# -# - Returns the full log, ANSI-stripped and IP-anonymized, capped at max_bytes -# ------------------------------------------------------------------------------ -get_full_log() { - local max_bytes="${1:-122880}" local logfile if declare -f ensure_log_on_host >/dev/null 2>&1; then ensure_log_on_host 2>/dev/null || true fi logfile=$(_tm_pick_logfile) [[ -z "$logfile" || ! -s "$logfile" ]] && return 0 - sed 's/\r$//' "$logfile" 2>/dev/null | - sed 's/\x1b\[[0-9;]*[a-zA-Z]//g' | - sed -E 's/([0-9]{1,3}\.)[0-9]{1,3}\.[0-9]{1,3}/\1x.x/g' | - head -c "$max_bytes" + _tm_focus <"$logfile" } -# ============================================================================== -# SECTION 3: STRUCTURED ERROR CAPTURE (.errinfo protocol) -# ============================================================================== -# -# When a command run via silent() fails, silent() writes ".errinfo": -# -# EXIT_CODE= -# LINE= -# COMMAND= -# --- OUTPUT --- -# -# -# error_handler() writes the same file for non-silent failures (best effort: -# tail of the active log). The HOST reads this file (pulling it from the -# container if needed) and builds the telemetry error field from it. -# ============================================================================== - -# ------------------------------------------------------------------------------ -# _tm_find_errinfo() -# -# - Locates the newest .errinfo file for this session -# - Honors TELEMETRY_ERRINFO override (set by the host after pulling the -# container's copy) -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# _tm_find_errinfo() -# -# - Locates the newest .errinfo file for this session -# - Honors TELEMETRY_ERRINFO override (set by the host after pulling the -# container's copy) -# ------------------------------------------------------------------------------ +# The capture for this failure: the container's (pulled by the host), else this side's. _tm_find_errinfo() { local candidate for candidate in \ "${TELEMETRY_ERRINFO:-}" \ "/tmp/.errinfo-${SESSION_ID:-none}" \ - "${INSTALL_LOG:-/nonexistent}.errinfo" \ - "${BUILD_LOG:-/nonexistent}.errinfo"; do + "${BUILD_LOG:-/nonexistent}.errinfo" \ + "${INSTALL_LOG:-/nonexistent}.errinfo"; do if [[ -n "$candidate" && -s "$candidate" ]]; then echo "$candidate" return 0 @@ -216,70 +150,7 @@ _tm_find_errinfo() { return 1 } -# ------------------------------------------------------------------------------ -# write_errinfo() -# -# - Writes a structured .errinfo file next to the given logfile -# - Arguments: -# * $1: target file path -# * $2: exit_code -# * $3: line number -# * $4: command (flattened to one line, truncated) -# * stdin: output segment of the failing command -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# write_errinfo() -# -# - Writes a structured .errinfo file next to the given logfile -# - Arguments: -# * $1: target file path -# * $2: exit_code -# * $3: line number -# * $4: command (flattened to one line, truncated) -# * stdin: output segment of the failing command -# ------------------------------------------------------------------------------ -write_errinfo() { - local target="$1" exit_code="$2" line="$3" command="$4" - command=$(printf '%s' "$command" | tr '\n' ' ' | head -c 300) - { - echo "EXIT_CODE=${exit_code}" - echo "LINE=${line}" - echo "COMMAND=${command}" - echo "--- OUTPUT ---" - _tm_clean_log | tail -n "${TELEMETRY_ERROR_MAX_LINES}" | head -c "${TELEMETRY_ERROR_MAX_BYTES}" - } >"$target" 2>/dev/null || true -} - -# ------------------------------------------------------------------------------ -# build_error_string() -# -# - Builds the final structured error string for telemetry: -# "exit_code=N | | at line L: \n---\n" -# - Sources, in priority order: -# 1. .errinfo file (exact output of the failing command) -# 2. FAILED_COMMAND/FAILED_LINE globals + filtered log tail -# 3. Explanation only -# - Arguments: -# * $1: exit_code -# * $2: log_text (optional override for the output section) -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# build_error_string() -# -# - Builds the final structured error string for telemetry: -# "exit_code=N | | at line L: \n---\n" -# - Sources, in priority order: -# 1. .errinfo file (exact output of the failing command) -# 2. FAILED_COMMAND/FAILED_LINE globals + filtered log tail -# 3. Explanation only -# - Arguments: -# * $1: exit_code -# * $2: log_text (optional override for the output section) -# ------------------------------------------------------------------------------ -# The table's curl and APT readings only hold when that tool ran. The error -# handler's guard knows which; the host always has it loaded. +# Tool-aware explanation when the error handler is loaded (it knows which tool ran). _tm_explain() { if [[ -n "${2:-}" ]] && declare -f _eh_explanation >/dev/null 2>&1; then _eh_explanation "$1" "$2" @@ -288,59 +159,92 @@ _tm_explain() { fi } -build_error_string() { - local exit_code="${1:-1}" - local log_text="${2:-}" - local explanation location="" cmd="" line="" errinfo="" +_tm_one_line() { + printf '%s' "$1" | tr '\n\t' ' ' | sed -E 's/ +/ /g; s/^ //; s/ $//' | head -c "${2:-300}" +} + +# ------------------------------------------------------------------------------ +# _tm_error_context +# +# Sets TM_ERR_{CODE,COMMAND,LINE,FUNCTION,STEP,MESSAGE,PHASE,OUTPUT,EXPLANATION} +# in the calling shell. A capture counts only when its code matches the one +# being reported (or that code is the generic 1/255 bash passes up); otherwise +# it belongs to an earlier failure. +# ------------------------------------------------------------------------------ +_tm_error_context() { + local exit_code="${1:-1}" errinfo="" captured="" + + TM_ERR_CODE="$exit_code" + TM_ERR_COMMAND="${FAILED_COMMAND:-}" + TM_ERR_LINE="${FAILED_LINE:-}" + TM_ERR_FUNCTION="${FAILED_FUNCTION:-}" + TM_ERR_STEP="${CS_STEP:-${CS_STEP_DONE:+after ${CS_STEP_DONE}}}" + TM_ERR_MESSAGE="${CS_ERROR_MSG:-}" + TM_ERR_PHASE="host" + TM_ERR_OUTPUT="" - # Prefer the structured capture from the failure moment if errinfo=$(_tm_find_errinfo); then - local captured_code - captured_code=$(sed -n 's/^EXIT_CODE=//p' "$errinfo" | head -1) - line=$(sed -n 's/^LINE=//p' "$errinfo" | head -1) - cmd=$(sed -n 's/^COMMAND=//p' "$errinfo" | head -1) - # Only trust the capture when it matches the reported failure (or the - # reported code is the generic 1 that bash propagates upward) - if [[ -n "$captured_code" && ("$captured_code" == "$exit_code" || "$exit_code" == "1" || "$exit_code" == "255") ]]; then - exit_code="$captured_code" - if [[ -z "$log_text" ]]; then - log_text=$(awk 'found{print} /^--- OUTPUT ---$/{found=1}' "$errinfo") + captured=$(sed -n 's/^EXIT_CODE=//p' "$errinfo" | head -n1) + if [[ -n "$captured" && ("$captured" == "$exit_code" || "$exit_code" == "1" || "$exit_code" == "255") ]]; then + TM_ERR_CODE="$captured" + TM_ERR_LINE=$(sed -n 's/^LINE=//p' "$errinfo" | head -n1) + TM_ERR_COMMAND=$(sed -n 's/^COMMAND=//p' "$errinfo" | head -n1) + TM_ERR_FUNCTION=$(sed -n 's/^FUNCTION=//p' "$errinfo" | head -n1) + local phase v + phase=$(sed -n 's/^PHASE=//p' "$errinfo" | head -n1) + [[ -z "$phase" && "$errinfo" == "/tmp/.errinfo-${SESSION_ID:-none}" ]] && phase="container" + if [[ "$phase" == "container" ]]; then + # The host's own message ("Installation failed in container ...") says nothing the container did not. + TM_ERR_PHASE="container" + TM_ERR_STEP=$(sed -n 's/^STEP=//p' "$errinfo" | head -n1) + TM_ERR_MESSAGE=$(sed -n 's/^MESSAGE=//p' "$errinfo" | head -n1) + else + v=$(sed -n 's/^STEP=//p' "$errinfo" | head -n1) + [[ -n "$v" ]] && TM_ERR_STEP="$v" + v=$(sed -n 's/^MESSAGE=//p' "$errinfo" | head -n1) + [[ -n "$v" ]] && TM_ERR_MESSAGE="$v" fi - else - cmd="" line="" + TM_ERR_OUTPUT=$(awk 'f{print} /^--- OUTPUT ---$/{f=1}' "$errinfo" | _tm_focus) fi fi - # Fall back to globals exported by silent()/error_handler - [[ -z "$cmd" && -n "${FAILED_COMMAND:-}" ]] && cmd="${FAILED_COMMAND}" - [[ -z "$line" && -n "${FAILED_LINE:-}" ]] && line="${FAILED_LINE}" + [[ -z "$TM_ERR_OUTPUT" ]] && TM_ERR_OUTPUT=$(get_error_log) + [[ "$TM_ERR_LINE" =~ ^[0-9]+$ ]] || TM_ERR_LINE="" + [[ "$TM_ERR_COMMAND" == "unknown" ]] && TM_ERR_COMMAND="" + [[ "$TM_ERR_FUNCTION" == "main" ]] && TM_ERR_FUNCTION="" - explanation=$(_tm_explain "$exit_code" "$cmd") - - if [[ -n "$cmd" ]]; then - if [[ -n "$line" ]]; then - location=$(printf ' | at line %s: %s' "$line" "$cmd") - else - location=$(printf ' | command: %s' "$cmd") - fi - fi + TM_ERR_COMMAND=$(_tm_one_line "$TM_ERR_COMMAND" 300) + TM_ERR_STEP=$(_tm_one_line "$TM_ERR_STEP" 120) + TM_ERR_MESSAGE=$(_tm_one_line "$TM_ERR_MESSAGE" 300 | sed -E 's/\b([0-9]{1,3})\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\b/\1.x.x.x/g') + TM_ERR_EXPLANATION=$(_tm_explain "$TM_ERR_CODE" "$TM_ERR_COMMAND") +} - # Last-resort output: filtered tail of the active log - if [[ -z "$log_text" ]]; then - log_text=$(get_error_log 40) || true +# _tm_format_error - the trace from TM_ERR_* (see _tm_error_context) +# +# exit_code=N | [ | step: S][ | in F][ | at line L: C] +# --- +# +_tm_format_error() { + local header="exit_code=${TM_ERR_CODE} | ${TM_ERR_EXPLANATION}" + [[ -n "$TM_ERR_STEP" ]] && header+=" | step: ${TM_ERR_STEP}" + [[ -n "$TM_ERR_FUNCTION" ]] && header+=" | in ${TM_ERR_FUNCTION}" + if [[ -n "$TM_ERR_COMMAND" && -n "$TM_ERR_LINE" ]]; then + header+=" | at line ${TM_ERR_LINE}: ${TM_ERR_COMMAND}" + elif [[ -n "$TM_ERR_COMMAND" ]]; then + header+=" | command: ${TM_ERR_COMMAND}" fi - if [[ -n "$log_text" ]]; then - printf 'exit_code=%s | %s%s\n---\n%s' "$exit_code" "$explanation" "$location" "$log_text" + if [[ -n "$TM_ERR_OUTPUT" ]]; then + printf '%s +--- +%s' "$header" "$TM_ERR_OUTPUT" else - printf 'exit_code=%s | %s%s' "$exit_code" "$explanation" "$location" + printf '%s' "$header" fi } -# ============================================================================== -# SECTION 4: SYSTEM INFO COLLECTION (collected once, sent with EVERY payload) -# ============================================================================== - -# ------------------------------------------------------------------------------ -# detect_gpu() - GPU vendor, model, passthrough type -# ------------------------------------------------------------------------------ +# build_error_string +build_error_string() { + _tm_error_context "${1:-1}" + _tm_format_error +} diff --git a/api/sysinfo.func b/api/sysinfo.func index 9256905..beaadd8 100644 --- a/api/sysinfo.func +++ b/api/sysinfo.func @@ -5,12 +5,8 @@ # ============================================================================== # API/SYSTEM AND ORIGIN DETECTION # ============================================================================== -# Part of the telemetry layer. Load api/api.func -- it sources every part -- -# rather than this file directly; the split is for maintenance only and no -# function name or behaviour changed with it. -# -# What the host is: repo the script came from, GPU, CPU, RAM, architecture. -# Read once and cached in TM_* variables. +# Where the script came from and what it runs on. Loaded through api/api.func; +# read once per run. # ============================================================================== [[ -n "${_API_SYSINFO_LOADED:-}" ]] && return 0 @@ -120,18 +116,6 @@ detect_repo_source() { # Run detection immediately when api.func is sourced detect_repo_source -# ============================================================================== -# SECTION 1: ERROR CODE DESCRIPTIONS & CATEGORIES -# ============================================================================== - -# ------------------------------------------------------------------------------ -# explain_exit_code() -# -# - Maps numeric exit codes to human-readable error descriptions -# - Canonical source of truth for ALL exit code mappings -# - Used by both api.func (telemetry) and error_handler.func (error display) -# ------------------------------------------------------------------------------ - # ------------------------------------------------------------------------------ # detect_gpu() - GPU vendor, model, passthrough type # ------------------------------------------------------------------------------ @@ -165,10 +149,6 @@ detect_gpu() { export GPU_VENDOR GPU_MODEL GPU_PASSTHROUGH } -# ------------------------------------------------------------------------------ -# detect_cpu() - CPU vendor and model -# ------------------------------------------------------------------------------ - # ------------------------------------------------------------------------------ # detect_cpu() - CPU vendor and model # ------------------------------------------------------------------------------ @@ -196,10 +176,6 @@ detect_cpu() { export CPU_VENDOR CPU_MODEL } -# ------------------------------------------------------------------------------ -# detect_ram() - RAM speed via dmidecode (empty in nested VMs) -# ------------------------------------------------------------------------------ - # ------------------------------------------------------------------------------ # detect_ram() - RAM speed via dmidecode (empty in nested VMs) # ------------------------------------------------------------------------------ @@ -216,10 +192,6 @@ detect_ram() { export RAM_SPEED } -# ------------------------------------------------------------------------------ -# detect_arm() - true when running on arm64 hardware -# ------------------------------------------------------------------------------ - # ------------------------------------------------------------------------------ # detect_arm() - true when running on arm64 hardware # ------------------------------------------------------------------------------ @@ -231,14 +203,6 @@ detect_arm() { export HAS_ARM } -# ------------------------------------------------------------------------------ -# telemetry_collect_sysinfo() -# -# - Collects ALL system metadata exactly once (cached via _TM_SYSINFO_DONE) -# - Sets: CPU_VENDOR, CPU_MODEL, GPU_VENDOR, GPU_MODEL, GPU_PASSTHROUGH, -# RAM_SPEED, HAS_ARM, TM_ARCH, TM_PVE_VERSION -# ------------------------------------------------------------------------------ - # ------------------------------------------------------------------------------ # telemetry_collect_sysinfo() # @@ -253,6 +217,7 @@ telemetry_collect_sysinfo() { [[ -z "${CPU_VENDOR:-}" ]] && detect_cpu [[ -z "${RAM_SPEED+x}" ]] && detect_ram [[ -z "${HAS_ARM:-}" ]] && detect_arm + [[ -z "${KERNEL_VERSION:-}" ]] && KERNEL_VERSION="$(uname -r 2>/dev/null)" # One vocabulary: dpkg says amd64/arm64, uname says x86_64/aarch64, so which a # run reported depended on whether dpkg existed. Normalised to dpkg's spelling, @@ -278,15 +243,6 @@ telemetry_collect_sysinfo() { fi _TM_SYSINFO_DONE=true - export TM_ARCH TM_PVE_VERSION TM_PLATFORM _TM_SYSINFO_DONE + export TM_ARCH TM_PVE_VERSION TM_PLATFORM KERNEL_VERSION _TM_SYSINFO_DONE } -# ============================================================================== -# SECTION 5: PAYLOAD BUILDER & SENDER -# ============================================================================== - -# ------------------------------------------------------------------------------ -# _tm_enabled() -# -# - Central gate: curl present, DIAGNOSTICS=yes, RANDOM_UUID set -# ------------------------------------------------------------------------------ diff --git a/api/telemetry.func b/api/telemetry.func index 899149c..1729e73 100644 --- a/api/telemetry.func +++ b/api/telemetry.func @@ -5,23 +5,14 @@ # ============================================================================== # API/TELEMETRY TRANSPORT # ============================================================================== -# Part of the telemetry layer. Load api/api.func -- it sources every part -- -# rather than this file directly; the split is for maintenance only and no -# function name or behaviour changed with it. -# -# Building the payload and sending it. Every send is best-effort: telemetry -# must never be the reason an install fails, which is also why a bug in here -# stays quiet -- treat changes with more care than the || true suggests. +# Payload and delivery. Loaded through api/api.func. Every send is best-effort: +# telemetry must never be the reason a run fails. # ============================================================================== [[ -n "${_API_TELEMETRY_LOADED:-}" ]] && return 0 _API_TELEMETRY_LOADED=1 -# ------------------------------------------------------------------------------ -# _tm_enabled() -# -# - Central gate: curl present, DIAGNOSTICS=yes, RANDOM_UUID set -# ------------------------------------------------------------------------------ +# curl present, opted in, session id set _tm_enabled() { command -v curl &>/dev/null || return 1 [[ "${DIAGNOSTICS:-no}" == "no" ]] && return 1 @@ -30,27 +21,11 @@ _tm_enabled() { } # ------------------------------------------------------------------------------ -# _tm_payload() -# -# - Builds the COMPLETE JSON payload. Every send (installing, progress ping, -# final status) carries the full metadata so no record is ever empty, -# regardless of which event the server persists. -# - Arguments: -# * $1: status -# * $2: exit_code (optional, default 0) -# * $3: error text (optional, raw - will be JSON-escaped here) -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# _tm_payload() +# _tm_payload [exit_code] [error_trace] # -# - Builds the COMPLETE JSON payload. Every send (installing, progress ping, -# final status) carries the full metadata so no record is ever empty, -# regardless of which event the server persists. -# - Arguments: -# * $1: status -# * $2: exit_code (optional, default 0) -# * $3: error text (optional, raw - will be JSON-escaped here) +# The full record. Every send carries all metadata, whichever event the server +# keeps. The error_* fields come from TM_ERR_* (_tm_error_context) and are only +# sent with a trace. # ------------------------------------------------------------------------------ _tm_payload() { local status="$1" @@ -59,8 +34,7 @@ _tm_payload() { telemetry_collect_sysinfo - # Numeric sanitation (server rejects out-of-range values) - [[ ! "$exit_code" =~ ^[0-9]+$ ]] && exit_code=1 + [[ ! "$exit_code" =~ ^[0-9]+$ ]] && exit_code=199 ((exit_code > 255)) && exit_code=255 local disk_size="${DISK_SIZE:-0}" @@ -74,31 +48,30 @@ _tm_payload() { ((duration > 86400)) && duration=86400 fi - local error_json="" error_category="" + local error_json="" error_category="" error_message="" error_step="" error_phase="" failed_function="" + local failed_command="" failed_line=0 if [[ -n "$error_raw" ]]; then error_json=$(json_escape "$error_raw") - error_category=$(categorize_error "$exit_code") + error_category=$(categorize_error "$exit_code" "${TM_ERR_COMMAND:-${FAILED_COMMAND:-}}") + error_step=$(json_escape "${TM_ERR_STEP:-}") + if [[ "$status" != "aborted" ]]; then + error_message=$(json_escape "${TM_ERR_MESSAGE:-}") + error_phase="${TM_ERR_PHASE:-}" + failed_function=$(json_escape "${TM_ERR_FUNCTION:-}") + failed_command=$(json_escape "${TM_ERR_COMMAND:-${FAILED_COMMAND:-}}") + failed_line="${TM_ERR_LINE:-${FAILED_LINE:-0}}" + fi fi + [[ ! "$failed_line" =~ ^[0-9]+$ ]] && failed_line=0 local gpu_model cpu_model gpu_model=$(json_escape "${GPU_MODEL:-}") cpu_model=$(json_escape "${CPU_MODEL:-}") - # What the container got, not what the host owns. This carried detect_gpu's - # verdict, which describes host hardware and is already in gpu_vendor and - # gpu_model. Whether the devices reached the container is the question the - # field name asks. + # Whether the devices reached the guest; the host's hardware is in gpu_vendor/gpu_model. local gpu_passthrough="no" [[ "${var_gpu:-no}" == "yes" || "${ENABLE_GPU:-no}" == "yes" ]] && gpu_passthrough="yes" - # The failing command and line as their own fields. They already exist as - # structured values in the error handler and were only ever flattened into the - # free-text error string, where grouping by them means parsing prose. - local failed_command failed_line - failed_command=$(json_escape "${FAILED_COMMAND:-}") - failed_line="${FAILED_LINE:-}" - [[ ! "$failed_line" =~ ^[0-9]+$ ]] && failed_line=0 - local app_version kernel_version app_version=$(json_escape "${APPLICATION_VERSION:-${var_appversion:-}}") kernel_version=$(json_escape "${KERNEL_VERSION:-}") @@ -122,6 +95,9 @@ _tm_payload() { "exit_code": ${exit_code}, "error": "${error_json}", "error_category": "${error_category}", + "error_message": "${error_message}", + "error_step": "${error_step}", + "error_phase": "${error_phase}", "install_duration": ${duration}, "cpu_vendor": "${CPU_VENDOR:-unknown}", "cpu_model": "${cpu_model}", @@ -136,6 +112,7 @@ _tm_payload() { "app_version": "${app_version}", "failed_command": "${failed_command}", "failed_line": ${failed_line}, + "failed_function": "${failed_function}", "repo_source": "${REPO_SOURCE}", "repo_slug": "${REPO_SLUG:-}" } @@ -143,25 +120,7 @@ EOF } # ------------------------------------------------------------------------------ -# _tm_send() -# -# - Single curl wrapper for all telemetry sends -# - Arguments: -# * $1: JSON payload -# * $2: timeout seconds (default TELEMETRY_TIMEOUT) -# * $3: attempts (default 1) -# - Returns 0 on HTTP 2xx, 1 otherwise. Never raises errors. -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# _tm_send() -# -# - Single curl wrapper for all telemetry sends -# - Arguments: -# * $1: JSON payload -# * $2: timeout seconds (default TELEMETRY_TIMEOUT) -# * $3: attempts (default 1) -# - Returns 0 on HTTP 2xx, 1 otherwise. Never raises errors. +# _tm_send [timeout] [attempts] - 0 on HTTP 2xx, 1 otherwise, never raises # ------------------------------------------------------------------------------ _tm_send() { local payload="$1" @@ -173,9 +132,6 @@ _tm_send() { if [[ "${DEV_MODE:-}" == "true" ]]; then echo "[DEBUG] telemetry POST (attempt ${attempt}/${attempts}): $payload" >&2 fi - # The User-Agent carries the payload version too. Without either, the server - # could only guess a client's age from which fields happened to be present, - # which makes any staged change to the schema a blind rollout. http_code=$(curl -sS -w "%{http_code}" -m "$timeout" -X POST "${TELEMETRY_URL}" \ -H "Content-Type: application/json" \ -A "community-scripts-core/${TELEMETRY_PAYLOAD_VERSION}" \ @@ -190,34 +146,17 @@ _tm_send() { } # ============================================================================== -# SECTION 6: PUBLIC TELEMETRY API +# PUBLIC API # ============================================================================== -# ------------------------------------------------------------------------------ -# post_to_api() -# -# - Sends the initial "installing" record for LXC container creation -# - Full metadata payload; retried up to 3x -# - Idempotent per execution (POST_TO_API_DONE) -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# post_to_api() -# -# - Sends the initial "installing" record for LXC container creation -# - Full metadata payload; retried up to 3x -# - Idempotent per execution (POST_TO_API_DONE) -# ------------------------------------------------------------------------------ +# post_to_api - the "installing" record; once per execution, retried 3x post_to_api() { [[ "${POST_TO_API_DONE:-}" == "true" ]] && return 0 _tm_enabled || return 0 TELEMETRY_TYPE="${TELEMETRY_TYPE:-lxc}" - # Start the clock at the first thing a run reports about itself. - # start_install_timer runs much later, after ID and storage selection, the - # template download and container creation -- so all of that was outside the - # measurement and anything failing earlier reported zero. + # The clock starts at the first report, so storage, template and create count too. [[ -z "${INSTALL_START_TIME:-}" ]] && export INSTALL_START_TIME="$(date +%s)" local payload @@ -230,51 +169,20 @@ post_to_api() { fi } -# ------------------------------------------------------------------------------ -# post_to_api_vm() -# -# - Sends the initial "installing" record for VM creation -# - Reads DIAGNOSTICS from /usr/local/community-scripts/diagnostics -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# post_to_api_vm() -# -# - Sends the initial "installing" record for VM creation -# - Reads DIAGNOSTICS from /usr/local/community-scripts/diagnostics -# ------------------------------------------------------------------------------ +# post_to_api_vm - same for a VM; reads the opt-in itself since no container set it post_to_api_vm() { [[ "${POST_TO_API_DONE:-}" == "true" ]] && return 0 - # A VM script runs before any container exists, so nothing has read the - # diagnostics opt-in into the environment yet. if [[ -f /usr/local/community-scripts/diagnostics ]]; then DIAGNOSTICS=$(grep -i "^DIAGNOSTICS=" /usr/local/community-scripts/diagnostics 2>/dev/null | awk -F'=' '{print $2}') || true fi - # post_to_api defaults TELEMETRY_TYPE with :-, so setting it here wins. TELEMETRY_TYPE="vm" CT_TYPE=2 post_to_api } -# ------------------------------------------------------------------------------ -# post_progress_to_api() -# -# - Progress ping ("validation" / "configuring") -# - Sends the FULL payload (not a minimal one) so that even if the server -# ever has to fall back to a progress row, it carries all metadata -# - Fire-and-forget, single attempt -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# post_progress_to_api() -# -# - Progress ping ("validation" / "configuring") -# - Sends the FULL payload (not a minimal one) so that even if the server -# ever has to fall back to a progress row, it carries all metadata -# - Fire-and-forget, single attempt -# ------------------------------------------------------------------------------ +# post_progress_to_api [status] - "validation"/"configuring" ping, full payload, one attempt post_progress_to_api() { _tm_enabled || return 0 @@ -285,39 +193,16 @@ post_progress_to_api() { } # ------------------------------------------------------------------------------ -# post_update_to_api() +# post_update_to_api [force] # -# - Reports the FINAL installation status. This is the single most important -# telemetry event - it must carry full metadata AND the focused error trace. -# - Arguments: -# * $1: status ("done"/"success" | "failed" | "aborted") -# * $2: exit_code (numeric; "none" → 0) -# * $3: "force" to bypass the duplicate guard (new information available) -# - Signal exit codes (129/130/143) are reported as "aborted", not "failed" -# - Idempotent via POST_UPDATE_DONE -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# post_update_to_api() -# -# - Reports the FINAL installation status. This is the single most important -# telemetry event - it must carry full metadata AND the focused error trace. -# - Arguments: -# * $1: status ("done"/"success" | "failed" | "aborted") -# * $2: exit_code (numeric; "none" → 0) -# * $3: "force" to bypass the duplicate guard (new information available) -# - Signal exit codes (129/130/143) are reported as "aborted", not "failed" -# - Idempotent via POST_UPDATE_DONE +# The terminal status, exactly once per execution ("force" reports again when +# the outcome changed, e.g. a retry succeeded). status: done|success, failed, +# aborted. exit_code "none" means 0; anything else non-numeric becomes 199. # ------------------------------------------------------------------------------ post_update_to_api() { command -v curl &>/dev/null || return 0 local status="${1:-failed}" - # Deliberately not defaulted to 1. A caller with nothing to report and a - # caller reporting a genuine general error are different facts, and 1 is what - # bash returns for every ordinary command failure -- defaulting to it made - # the two indistinguishable in the data. - local raw_exit_code="${2-}" local force="${3:-}" @@ -329,22 +214,14 @@ post_update_to_api() { [[ "${DIAGNOSTICS:-no}" == "no" ]] && return 0 [[ -z "${RANDOM_UUID:-}" ]] && return 0 - # A status for an execution the service never saw an install for is an orphan. - # Unset means post_to_api was never attempted -- an update run, or an exit - # before the install began. "false" means it was attempted and the send - # failed, which is still worth reporting. + # Unset: no install was ever reported (an update run, or an exit before the + # install began). "false" means the send failed and is still worth a status. [[ -z "${POST_TO_API_DONE:-}" ]] && return 0 local exit_code=0 if [[ "$raw_exit_code" =~ ^[0-9]+$ ]]; then exit_code="$raw_exit_code" - elif [[ "$raw_exit_code" == "none" ]]; then - exit_code=0 - else - # Neither a number nor "none": the code was never passed, or was lost on - # the way up. 199 says exactly that, where 1 used to claim a general error - # the engine never observed. - + elif [[ "$raw_exit_code" != "none" ]]; then exit_code=199 fi @@ -358,13 +235,7 @@ post_update_to_api() { pb_status="aborted" ;; failed) - # Codes the engine raises when the person at the keyboard said no. A signal - # is the obvious case; 113, 114, 122 and 254 are the engine asking a - # question and being told no, and 253 is an update the user declined to - # migrate. Filing those as failures put user decisions in the failure rate: - # "exit 113" was one of the largest single signatures on the dashboard, - # sitting under exit code 1 in category "shell". - + # The engine asking a question and being told no, and signals: user decisions, not failures. case "$exit_code" in 113 | 114 | 122 | 129 | 130 | 143 | 253 | 254) pb_status="aborted" ;; *) pb_status="failed" ;; @@ -376,10 +247,13 @@ post_update_to_api() { esac if [[ "$pb_status" == "failed" || "$pb_status" == "unknown" ]]; then - error_raw=$(build_error_string "$exit_code") + _tm_error_context "$exit_code" + exit_code="$TM_ERR_CODE" + error_raw=$(_tm_format_error) elif [[ "$pb_status" == "aborted" ]]; then - # Short context line only - no log dump for user aborts - error_raw="exit_code=${exit_code} | $(explain_exit_code "$exit_code")" + TM_ERR_STEP="${CS_STEP:-${CS_STEP_DONE:+after ${CS_STEP_DONE}}}" + TM_ERR_COMMAND="" + error_raw="exit_code=${exit_code} | $(explain_exit_code "$exit_code")${TM_ERR_STEP:+ | step: ${TM_ERR_STEP}}" ERROR_CATEGORY_OVERRIDE="${ERROR_CATEGORY_OVERRIDE:-user_aborted}" fi @@ -391,169 +265,77 @@ post_update_to_api() { return 0 fi - # Retry with a smaller error trace (in case the payload was the problem) + # The payload itself may be the problem: retry with the header line only. if [[ -n "$error_raw" ]]; then - local short_error - short_error="exit_code=${exit_code} | $(_tm_explain "$exit_code" "${FAILED_COMMAND:-}")" - [[ -n "${FAILED_COMMAND:-}" ]] && short_error+=" | at line ${FAILED_LINE:-?}: $(printf '%s' "$FAILED_COMMAND" | head -c 200)" - payload=$(_tm_payload "$pb_status" "$exit_code" "$short_error") + payload=$(_tm_payload "$pb_status" "$exit_code" "$(head -n1 <<<"$error_raw" | head -c 600)") if _tm_send "$payload" "$STATUS_TIMEOUT" 2; then POST_UPDATE_DONE=true return 0 fi fi - # All attempts failed - leave POST_UPDATE_DONE=false so the EXIT trap can retry + # Left false so the EXIT trap can try once more. return 0 } # ------------------------------------------------------------------------------ -# telemetry_new_attempt() +# _tm_post_run - tool and add-on runs # -# - Resets telemetry state for a RETRY of the same session (recovery menu: -# rebuild, OOM retry, DNS retry, APT repair). Each attempt becomes its own -# execution on the server (the previous one keeps its terminal status). -# ------------------------------------------------------------------------------ - +# Each run is its own execution with a fresh id. Failures carry the same error +# fields as installs. # ------------------------------------------------------------------------------ -# post_tool_to_api() - PVE host tool usage report -# ------------------------------------------------------------------------------ -post_tool_to_api() { +_tm_post_run() { command -v curl &>/dev/null || return 0 [[ "${DIAGNOSTICS:-no}" == "no" ]] && return 0 - local tool_name="${1:-unknown}" - local status="${2:-success}" - local exit_code="${3:-0}" - local error="" error_category="" - local uuid duration - - uuid=$(cat /proc/sys/kernel/random/uuid 2>/dev/null || uuidgen 2>/dev/null || echo "tool-$(date +%s)") - duration=$(get_install_duration) + local type="$1" name="${2:-unknown}" status="${3:-success}" exit_code="${4:-0}" + local uuid error_raw="" payload + uuid=$(cat /proc/sys/kernel/random/uuid 2>/dev/null || uuidgen 2>/dev/null || echo "${type}-$(date +%s)") [[ "$status" == "done" ]] && status="success" + [[ "$exit_code" =~ ^[0-9]+$ ]] || exit_code=199 if [[ "$status" == "failed" ]]; then - [[ ! "$exit_code" =~ ^[0-9]+$ ]] && exit_code=1 - error=$(json_escape "$(build_error_string "$exit_code")") - error_category=$(categorize_error "$exit_code") + _tm_error_context "$exit_code" + exit_code="$TM_ERR_CODE" + error_raw=$(_tm_format_error) fi - telemetry_collect_sysinfo - - local JSON_PAYLOAD - JSON_PAYLOAD=$( - cat < [status] [exit_code] - a PVE host tool ran +post_tool_to_api() { + _tm_post_run "${TELEMETRY_TOOL_TYPE:-pve}" "$@" } -# ------------------------------------------------------------------------------ -# post_addon_to_api() - Addon installation report (runs inside containers) -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# post_addon_to_api() - Addon installation report (runs inside containers) -# ------------------------------------------------------------------------------ +# post_addon_to_api [status] [exit_code] - an add-on ran inside a container post_addon_to_api() { - command -v curl &>/dev/null || return 0 - [[ "${DIAGNOSTICS:-no}" == "no" ]] && return 0 - - local addon_name="${1:-unknown}" - local status="${2:-success}" - local exit_code="${3:-0}" - local error="" error_category="" - local uuid duration - - uuid=$(cat /proc/sys/kernel/random/uuid 2>/dev/null || uuidgen 2>/dev/null || echo "addon-$(date +%s)") - duration=$(get_install_duration) - - [[ "$status" == "done" ]] && status="success" - - if [[ "$status" == "failed" ]]; then - [[ ! "$exit_code" =~ ^[0-9]+$ ]] && exit_code=1 - error=$(json_escape "$(build_error_string "$exit_code")") - error_category=$(categorize_error "$exit_code") - fi - local os_type="" os_version="" if [[ -f /etc/os-release ]]; then os_type=$(grep "^ID=" /etc/os-release | cut -d= -f2 | tr -d '"' || true) os_version=$(grep "^VERSION_ID=" /etc/os-release | cut -d= -f2 | tr -d '"' || true) fi - - # TM_PLATFORM, not TELEMETRY_PLATFORM. The latter is exported into the - # container only while it is being built and never written to disk, so an addon - # running weeks later saw an empty string every single time -- the field was - # unconditionally blank in every addon record ever sent. - telemetry_collect_sysinfo - - local JSON_PAYLOAD - JSON_PAYLOAD=$( - cat </dev/null + unset _SILENT_FAILED_RC _SILENT_FAILED_CMD _SILENT_FAILED_LINE _SILENT_FAILED_LOG +} + silent() { _cs_reattach_output # A failure the caller handled (a retry loop) must not be reported for a later, unrelated error. @@ -1027,32 +1033,19 @@ silent() { export _SILENT_FAILED_LINE="$caller_line" export _SILENT_FAILED_LOG="$logfile" - # ── Structured error capture (.errinfo) ── - # Extract exactly THIS command's output (from the recorded byte offset), - # strip ANSI/progress noise, keep the last 60 lines. This file is the - # primary source for the telemetry error trace - self-contained, no - # api.func dependency (containers don't source api.func). - local flat_cmd - flat_cmd=$(printf '%s' "$cmd" | tr '\n' ' ' | head -c 300) { echo "EXIT_CODE=${rc}" echo "LINE=${caller_line}" - echo "COMMAND=${flat_cmd}" + echo "COMMAND=$(printf '%s' "$cmd" | tr '\n' ' ' | head -c 300)" + echo "FUNCTION=${FUNCNAME[1]:-}" + echo "STEP=${CS_STEP:-}" echo "--- OUTPUT ---" if [[ -s "$logfile" ]]; then - local segment - segment=$(tail -c +"$((start_bytes + 1))" "$logfile" 2>/dev/null | - sed 's/\r$//' | - sed 's/\x1b\[[0-9;]*[a-zA-Z]//g' | - grep -avE '^(Get:|Hit:|Ign:|Fetched |Reading package lists|Reading state information|Building dependency tree|Selecting previously|Preparing to unpack|Unpacking |Processing triggers for|\(Reading database|[0-9]+%[[:space:]]*\[)' | - grep -avE '^[[:space:]]*$' | - tail -n 60) - # If the noise filter swallowed everything, fall back to the raw tail - if [[ -z "$segment" ]]; then - segment=$(tail -c +"$((start_bytes + 1))" "$logfile" 2>/dev/null | - sed 's/\r$//' | sed 's/\x1b\[[0-9;]*[a-zA-Z]//g' | tail -n 60) + if declare -f _tm_clean_log >/dev/null 2>&1; then + tail -c +"$((start_bytes + 1))" "$logfile" 2>/dev/null | _tm_clean_log | tail -n 60 | head -c 10240 + else + tail -c +"$((start_bytes + 1))" "$logfile" 2>/dev/null | sed 's/\r$//; s/\x1b\[[0-9;]*[a-zA-Z]//g' | tail -n 200 | head -c 32768 fi - printf '%s' "$segment" | head -c 10240 fi } >"$errinfo" 2>/dev/null || true @@ -1279,6 +1272,10 @@ msg_info() { _cs_reattach_output local msg="$1" [[ -z "$msg" ]] && return + # Read by the error handler and telemetry: which step failed, and what it said. + CS_STEP="$(strip_ansi "$msg")" + CS_ERROR_MSG="" + _cs_drop_silent_record if ! declare -p MSG_INFO_SHOWN &>/dev/null || ! declare -A MSG_INFO_SHOWN &>/dev/null; then declare -gA MSG_INFO_SHOWN=() @@ -1338,6 +1335,10 @@ msg_ok() { _cs_reattach_output local msg="$1" [[ -z "$msg" ]] && return + CS_STEP_DONE="$(strip_ansi "$msg")" + CS_STEP="" + CS_ERROR_MSG="" + _cs_drop_silent_record stop_spinner ((${#_MSG_BLOCKS[@]})) && unset '_MSG_BLOCKS[-1]' clear_line @@ -1362,6 +1363,7 @@ msg_error() { stop_spinner _MSG_BLOCKS=() local msg="$1" + [[ -z "${CS_ERROR_MSG:-}" && -z "${_EH_REPORTING:-}" ]] && CS_ERROR_MSG="$(strip_ansi "$msg")" echo -e "${BFR:-}${CROSS:-✖️}${RD}${msg}${CL}" >&2 log_msg "[ERROR] $msg" } diff --git a/core/error_handler.func b/core/error_handler.func index dc13f16..821ba9a 100644 --- a/core/error_handler.func +++ b/core/error_handler.func @@ -7,209 +7,16 @@ # License: MIT | https://github.com/community-scripts/ProxmoxVE/raw/main/LICENSE # ------------------------------------------------------------------------------ # -# Provides error handling and signal management for all scripts. -# -# TELEMETRY CONTRACT (v3): -# - HOST context: this file reports terminal statuses via post_update_to_api -# (full metadata + focused error trace). -# - CONTAINER context: this file NEVER talks to the telemetry API. It writes -# two local artifacts that the host picks up after lxc-attach returns: -# /root/.install-.failed → exit code (flag file) -# /root/.install-.log.errinfo → structured error capture -# This guarantees the server only ever sees ONE terminal event per -# execution - the host's complete one. -# -# Usage: -# source <(curl -fsSL .../error_handler.func) -# catch_errors +# ERR/EXIT/signal traps for every script: catch_errors. # +# On the host the failure is reported with post_update_to_api. Inside the +# container nothing is sent; the host reads two files after the install returns: +# /root/.install-.failed exit code +# /root/.install-.log.errinfo capture (format: api/errorlog.func) # ------------------------------------------------------------------------------ # ============================================================================== -# SECTION 1: EXIT CODE EXPLANATIONS (fallback) -# ============================================================================== - -# ------------------------------------------------------------------------------ -# explain_exit_code() -# -# - Canonical version lives in api.func (sourced before this file on the host) -# - This fallback covers the container context where api.func is not sourced -# ------------------------------------------------------------------------------ -if ! declare -f explain_exit_code &>/dev/null; then - explain_exit_code() { - local code="$1" - case "$code" in - 1) echo "The command failed; its output says why" ;; - 2) echo "The command failed with status 2 (a usage error for most tools); its output says why" ;; - 3) echo "The command failed with status 3; its output says why" ;; - 10) echo "Docker / privileged mode required (unsupported environment)" ;; - 4) echo "curl: Feature not supported or protocol error" ;; - 5) echo "curl: Could not resolve proxy" ;; - 6) echo "curl: DNS resolution failed (could not resolve host)" ;; - 7) echo "curl: Failed to connect (network unreachable / host down)" ;; - 8) echo "curl: Server reply error (FTP/SFTP or apk untrusted key)" ;; - 16) echo "curl: HTTP/2 framing layer error" ;; - 18) echo "curl: Partial file (transfer not completed)" ;; - 22) echo "curl: HTTP error returned (404, 429, 500+)" ;; - 23) echo "curl: Write error (disk full or permissions)" ;; - 24) echo "curl: Write to local file failed" ;; - 25) echo "curl: Upload failed" ;; - 26) echo "curl: Read error on local file (I/O)" ;; - 27) echo "curl: Out of memory (memory allocation failed)" ;; - 28) echo "curl: Operation timeout (network slow or server not responding)" ;; - 30) echo "curl: FTP port command failed" ;; - 32) echo "curl: FTP SIZE command failed" ;; - 33) echo "curl: HTTP range error" ;; - 34) echo "curl: HTTP post error" ;; - 35) echo "curl: SSL/TLS handshake failed (certificate error)" ;; - 36) echo "curl: FTP bad download resume" ;; - 39) echo "curl: LDAP search failed" ;; - 44) echo "curl: Internal error (bad function call order)" ;; - 45) echo "curl: Interface error (failed to bind to specified interface)" ;; - 46) echo "curl: Bad password entered" ;; - 47) echo "curl: Too many redirects" ;; - 48) echo "curl: Unknown command line option specified" ;; - 51) echo "curl: SSL peer certificate or SSH host key verification failed" ;; - 52) echo "curl: Empty reply from server (got nothing)" ;; - 55) echo "curl: Failed sending network data" ;; - 56) echo "curl: Receive error (connection reset by peer)" ;; - 57) echo "curl: Unrecoverable poll/select error (system I/O failure)" ;; - 59) echo "curl: Couldn't use specified SSL cipher" ;; - 61) echo "curl: Bad/unrecognized transfer encoding" ;; - 63) echo "curl: Maximum file size exceeded" ;; - 75) echo "Temporary failure (retry later)" ;; - 78) echo "curl: Remote file not found (404 on FTP/file)" ;; - 79) echo "curl: SSH session error (key exchange/auth failed)" ;; - 92) echo "curl: HTTP/2 stream error (protocol violation)" ;; - 95) echo "curl: HTTP/3 layer error" ;; - 64) echo "Usage error (wrong arguments)" ;; - 65) echo "Data format error (bad input data)" ;; - 66) echo "Input file not found (cannot open input)" ;; - 67) echo "User not found (addressee unknown)" ;; - 68) echo "Host not found (hostname unknown)" ;; - 69) echo "Service unavailable" ;; - 70) echo "Internal software error" ;; - 71) echo "System error (OS-level failure)" ;; - 72) echo "Critical OS file missing" ;; - 73) echo "Cannot create output file" ;; - 74) echo "I/O error" ;; - 76) echo "Remote protocol error" ;; - 77) echo "Permission denied" ;; - 100) echo "APT: Package manager error (broken packages / dependency problems)" ;; - 101) echo "APT: Configuration error (bad sources.list, malformed config)" ;; - 102) echo "APT: Lock held by another process (dpkg/apt still running)" ;; - 103) echo "Validation: Shell is not Bash" ;; - 104) echo "Validation: Not running as root (or invoked via sudo)" ;; - 105) echo "Validation: Proxmox VE version not supported" ;; - 106) echo "Validation: Unsupported architecture (requires amd64 or arm64)" ;; - 107) echo "Validation: Kernel key parameters unreadable" ;; - 108) echo "Validation: Kernel key limits exceeded" ;; - 109) echo "Proxmox: No available container ID after max attempts" ;; - 110) echo "Proxmox: Failed to apply default.vars" ;; - 111) echo "Proxmox: App defaults file not available" ;; - 112) echo "Proxmox: Invalid install menu option" ;; - 113) echo "LXC: Under-provisioned — user aborted update" ;; - 114) echo "LXC: Storage too low — user aborted update" ;; - 115) echo "Download: install.func download failed or incomplete" ;; - 116) echo "Proxmox: Default bridge vmbr0 not found" ;; - 117) echo "LXC: Container did not reach running state" ;; - 118) echo "LXC: No IP assigned to container after timeout" ;; - 119) echo "Proxmox: No valid storage for rootdir content" ;; - 120) echo "Proxmox: No valid storage for vztmpl content" ;; - 121) echo "LXC: Container network not ready (no IP after retries)" ;; - 122) echo "LXC: No internet connectivity — user declined to continue" ;; - 123) echo "LXC: Local IP detection failed" ;; - 124) echo "Command timed out (timeout command)" ;; - 125) echo "Command failed to start (Docker daemon or execution error)" ;; - 126) echo "Command invoked cannot execute (permission problem?)" ;; - 127) echo "Command not found" ;; - 128) echo "git: Fatal error (repository, network or permission problem)" ;; - 129) echo "Killed by SIGHUP (terminal closed / hangup)" ;; - 130) echo "Aborted by user (SIGINT)" ;; - 131) echo "Killed by SIGQUIT (core dumped)" ;; - 132) echo "Killed by SIGILL (illegal CPU instruction)" ;; - 134) echo "Process aborted (SIGABRT - possibly Node.js heap overflow)" ;; - 137) echo "Killed (SIGKILL / Out of memory?)" ;; - 139) echo "Segmentation fault (core dumped)" ;; - 141) echo "Broken pipe (SIGPIPE - output closed prematurely)" ;; - 143) echo "Terminated (SIGTERM)" ;; - 144) echo "Killed by signal 16 (SIGUSR1 / SIGSTKFLT)" ;; - 146) echo "Killed by signal 18 (SIGTSTP)" ;; - 150) echo "Systemd: Service failed to start" ;; - 151) echo "Systemd: Service unit not found" ;; - 152) echo "Permission denied (EACCES)" ;; - 153) echo "Build/compile failed (make/gcc/cmake)" ;; - 154) echo "Node.js: Native addon build failed (node-gyp)" ;; - 160) echo "Python: Virtualenv / uv environment missing or broken" ;; - 161) echo "Python: Dependency resolution failed" ;; - 162) echo "Python: Installation aborted (permissions or EXTERNALLY-MANAGED)" ;; - 170) echo "PostgreSQL: Connection failed (server not running / wrong socket)" ;; - 171) echo "PostgreSQL: Authentication failed (bad user/password)" ;; - 172) echo "PostgreSQL: Database does not exist" ;; - 173) echo "PostgreSQL: Fatal error in query / syntax" ;; - 180) echo "MySQL/MariaDB: Connection failed (server not running / wrong socket)" ;; - 181) echo "MySQL/MariaDB: Authentication failed (bad user/password)" ;; - 182) echo "MySQL/MariaDB: Database does not exist" ;; - 183) echo "MySQL/MariaDB: Fatal error in query / syntax" ;; - 190) echo "MongoDB: Connection failed (server not running)" ;; - 191) echo "MongoDB: Authentication failed (bad user/password)" ;; - 192) echo "MongoDB: Database not found" ;; - 193) echo "MongoDB: Fatal query error" ;; - 199) echo "Engine: exit code not reported" ;; - 200) echo "Proxmox: Failed to create lock file" ;; - 203) echo "Proxmox: Missing CTID variable" ;; - 204) echo "Proxmox: Missing PCT_OSTYPE variable" ;; - 205) echo "Proxmox: Invalid CTID (<100)" ;; - 206) echo "Proxmox: CTID already in use" ;; - 207) echo "Proxmox: Password contains unescaped special characters" ;; - 208) echo "Proxmox: Invalid container settings (network, DNS, RAM, password, mounts)" ;; - 209) echo "Proxmox: Container creation failed" ;; - 210) echo "Proxmox: Cluster not quorate" ;; - 211) echo "Proxmox: Timeout waiting for template lock" ;; - 212) echo "Proxmox: Storage type 'iscsidirect' does not support containers (VMs only)" ;; - 213) echo "Proxmox: Storage type does not support 'rootdir' content" ;; - 214) echo "Proxmox: Not enough storage space" ;; - 215) echo "Proxmox: Container created but not listed (ghost state)" ;; - 216) echo "Proxmox: RootFS entry missing in config" ;; - 217) echo "Proxmox: Storage not accessible" ;; - 218) echo "Proxmox: Template file corrupted or incomplete" ;; - 219) echo "Proxmox: CephFS does not support containers - use RBD" ;; - 220) echo "Proxmox: Unable to resolve template path" ;; - 221) echo "Proxmox: Template file not readable" ;; - 222) echo "Proxmox: Template download failed" ;; - 223) echo "Proxmox: Template not available after download" ;; - 224) echo "Proxmox: PBS storage is for backups only" ;; - 225) echo "Proxmox: No template available for OS/Version" ;; - 226) echo "Proxmox: VM disk import or post-creation setup failed" ;; - 228) echo "Proxmox: Cluster filesystem /etc/pve not available" ;; - 231) echo "Proxmox: LXC stack too old for the template, or its upgrade failed" ;; - 232) echo "Tools: Wrong execution environment (run on PVE host, not inside LXC)" ;; - 233) echo "Tools: Application not installed (update prerequisite missing)" ;; - 234) echo "Tools: No LXC containers found or available" ;; - 235) echo "Tools: Backup or restore operation failed" ;; - 236) echo "Tools: Required hardware not detected" ;; - 237) echo "Tools: Dependency package installation failed" ;; - 238) echo "Tools: OS or distribution not supported for this addon" ;; - 239) echo "npm/Node.js: Unexpected runtime error or dependency failure" ;; - 243) echo "Node.js: Out of memory (JavaScript heap out of memory)" ;; - 245) echo "Node.js: Invalid command-line option" ;; - 246) echo "Node.js: Internal JavaScript Parse Error" ;; - 247) echo "Node.js: Fatal internal error" ;; - 248) echo "Node.js: Invalid C++ addon / N-API failure" ;; - 249) echo "npm/pnpm/yarn: Unknown fatal error" ;; - 250) echo "App: Download failed or version not determined" ;; - 251) echo "App: File extraction failed (corrupt or incomplete archive)" ;; - 252) echo "App: Required file or resource not found" ;; - 253) echo "App: Data migration required — update aborted" ;; - 254) echo "App: User declined prompt or input timed out" ;; - 255) echo "DPKG: Fatal internal error" ;; - *) echo "Unknown error" ;; - esac - } -fi - -# ============================================================================== -# SECTION 2: CONTEXT DETECTION & CONTAINER ARTIFACTS +# SECTION 1: CONTEXT DETECTION & CONTAINER ARTIFACTS # ============================================================================== # ------------------------------------------------------------------------------ @@ -240,14 +47,44 @@ _is_container_context() { } # ------------------------------------------------------------------------------ -# _container_write_failure() +# _eh_write_errinfo [silent capture] # -# - Writes the failure artifacts inside the container for the host to pick up: -# * flag file with the exit code -# * .errinfo capture (if silent() has not already written a better one) -# * copy of the install log -# - This REPLACES any direct telemetry send from the container -# - Arguments: $1 = exit_code, $2 = command (optional), $3 = line (optional) +# The capture for the failure being reported. With a silent() capture its +# output is kept (it is the failing command's own); otherwise the failing step's +# lines from the active log. +# ------------------------------------------------------------------------------ +_eh_write_errinfo() { + local target="$1" exit_code="$2" command="$3" line="$4" from="${5:-}" log output="" + if [[ -n "$from" && -s "$from" ]]; then + output="$(awk 'f{print} /^--- OUTPUT ---$/{f=1}' "$from")" + else + log="${_EH_ACTIVE_LOG:-${INSTALL_LOG:-}}" + if [[ -n "$log" && -s "$log" ]]; then + if declare -f _tm_focus >/dev/null 2>&1; then + output="$(_tm_focus <"$log")" + else + output="$(tail -n 60 "$log" | sed 's/\r$//; s/\x1b\[[0-9;]*[a-zA-Z]//g')" + fi + fi + fi + { + echo "EXIT_CODE=${exit_code}" + echo "LINE=${line:-0}" + echo "COMMAND=$(printf '%s' "${command:-unknown}" | tr '\n' ' ' | head -c 300)" + echo "FUNCTION=${FAILED_FUNCTION:-}" + echo "STEP=${CS_STEP:-${CS_STEP_DONE:+after ${CS_STEP_DONE}}}" + echo "MESSAGE=$(printf '%s' "${CS_ERROR_MSG:-}" | tr '\n' ' ' | head -c 300)" + _is_container_context && echo "PHASE=container" || echo "PHASE=host" + echo "--- OUTPUT ---" + printf '%s\n' "$output" + } >"${target}.tmp" 2>/dev/null && mv -f "${target}.tmp" "$target" 2>/dev/null || true +} + +# ------------------------------------------------------------------------------ +# _container_write_failure [command] [line] +# +# The container's side of a failure: the exit code flag, the install log where +# the host looks for it, and the capture (written once, by the first caller). # ------------------------------------------------------------------------------ _container_write_failure() { local exit_code="${1:-1}" @@ -255,35 +92,15 @@ _container_write_failure() { local line="${3:-}" local sid="${SESSION_ID:-error}" - # Flag file with exit code (host reads this after lxc-attach returns) echo "$exit_code" >"/root/.install-${sid}.failed" 2>/dev/null || true - # Keep the install log where the host expects it if [[ -n "${INSTALL_LOG:-}" && -f "${INSTALL_LOG}" && "${INSTALL_LOG}" != "/root/.install-${sid}.log" ]]; then cp "${INSTALL_LOG}" "/root/.install-${sid}.log" 2>/dev/null || true fi - # Structured error capture (skip if silent() already wrote the exact - # output segment of the failing command - that one is always better). - # Self-contained: api.func is NOT sourced inside containers. local errinfo="${INSTALL_LOG:-/root/.install-${sid}.log}.errinfo" - if [[ ! -s "$errinfo" ]]; then - local flat_cmd - flat_cmd=$(printf '%s' "${command:-unknown}" | tr '\n' ' ' | head -c 300) - { - echo "EXIT_CODE=${exit_code}" - echo "LINE=${line:-0}" - echo "COMMAND=${flat_cmd}" - echo "--- OUTPUT ---" - if [[ -n "${INSTALL_LOG:-}" && -s "${INSTALL_LOG}" ]]; then - tail -n 80 "${INSTALL_LOG}" 2>/dev/null | - sed 's/\r$//' | - sed 's/\x1b\[[0-9;]*[a-zA-Z]//g' | - grep -avE '^(Get:|Hit:|Ign:|Fetched |Reading package lists|Reading state information|Building dependency tree|Selecting previously|Preparing to unpack|Unpacking |Processing triggers for|\(Reading database|[0-9]+%[[:space:]]*\[)' | - grep -avE '^[[:space:]]*$' | - tail -n 60 | head -c 10240 - fi - } >"$errinfo" 2>/dev/null || true + if [[ "${_EH_ERRINFO_DONE:-}" != "$errinfo" ]]; then + _eh_write_errinfo "$errinfo" "$exit_code" "$command" "$line" fi } @@ -327,24 +144,67 @@ _eh_ok() { fi } +# _eh_command_word - the program a command line runs, without +# assignments, wrappers or a path: "FOO=1 $STD /usr/bin/npm ci" -> npm +_eh_command_word() { + local word + for word in $1; do + [[ "$word" =~ ^[A-Za-z_][A-Za-z0-9_]*= ]] && continue + case "$word" in + sudo | env | command | exec | nohup | time | silent | _cs_shield_hangup | '$STD' | -*) continue ;; + esac + printf '%s' "${word##*/}" + return + done +} + # ------------------------------------------------------------------------------ -# _eh_explanation() - human-readable cause, printed on stdout +# _eh_explanation - what the exit status means here # -# explain_exit_code borrows curl's numbering for a large block of codes. Those -# readings are only right if curl is what actually ran, so they are dropped when -# the failing command was something else. +# A table entry that belongs to one tool family (curl, APT, Node.js, ...) only +# holds when that tool ran: cargo's 101 is a panic, not an APT error. Otherwise +# the sentence names the program that failed. # ------------------------------------------------------------------------------ -# A tool-specific explanation only holds when the failing command is that tool: -# cargo's 101 is a panic, not an APT configuration error. _eh_explanation() { - local exit_code="$1" command="$2" explanation tools - explanation="$(explain_exit_code "$exit_code")" - tools="$(_eh_tools_for "${explanation%%:*}")" - if [[ -n "$tools" ]] && ! _eh_command_is "$command" "$tools"; then - explanation="Command failed with exit status ${exit_code}" + local exit_code="$1" command="$2" explanation tools word + if declare -f explain_exit_code >/dev/null 2>&1; then + explanation="$(explain_exit_code "$exit_code")" + else + explanation="Exit status ${exit_code}" + fi + word="$(_eh_command_word "$command")" + + case "$command" in + "(("*) + [[ "$exit_code" == 1 ]] && { printf 'Arithmetic expression evaluated to 0'; return; } + ;; + "[["* | "[ "* | "test "*) + [[ "$exit_code" == 1 ]] && { printf 'Test condition was false'; return; } + ;; + esac + if [[ "$command" =~ ^[A-Za-z_][A-Za-z0-9_]*=\$\( ]]; then + printf 'Command substitution exited with status %s' "$exit_code" + return + fi + if [[ "$exit_code" == 1 && "$word" =~ ^(grep|egrep|fgrep|zgrep|rg)$ ]]; then + printf '%s found no match' "$word" + return fi if [[ "$exit_code" == 5 ]] && _eh_command_is "$command" "systemctl"; then - explanation="Systemd: unit not found" + printf 'Systemd: unit not found' + return + fi + if [[ "$word" == "return" || "$word" == "exit" ]]; then + printf 'Exit status %s' "$exit_code" + return + fi + + tools="$(_eh_tools_for "${explanation%%:*}")" + if [[ -n "$tools" ]] && ! _eh_command_is "$command" "$tools"; then + explanation="${word:+${word} exited with status ${exit_code}}" + explanation="${explanation:-Exit status ${exit_code}}" + elif [[ "$exit_code" =~ ^[123]$ && -n "$word" ]]; then + explanation="${word} exited with status ${exit_code}" fi printf '%s' "$explanation" } @@ -371,16 +231,23 @@ _eh_command_is() { } # ------------------------------------------------------------------------------ -# _eh_report() - the one terminal event for this execution +# _eh_report [silent capture] # -# Host reports to the API; container only leaves artifacts behind, so the server -# sees the host's complete event rather than two partial ones. -# Arguments: exit_code, command, line +# The one terminal event for this execution: the container leaves its files for +# the host, the host sends it. # ------------------------------------------------------------------------------ _eh_report() { + local errinfo if _is_container_context; then + errinfo="${INSTALL_LOG:-/root/.install-${SESSION_ID:-error}.log}.errinfo" + _eh_write_errinfo "$errinfo" "$1" "$2" "$3" "${4:-}" + _EH_ERRINFO_DONE="$errinfo" _container_write_failure "$1" "$2" "$3" elif declare -f post_update_to_api &>/dev/null; then + if [[ -n "${_EH_ACTIVE_LOG:-}" ]]; then + _eh_write_errinfo "${_EH_ACTIVE_LOG}.errinfo" "$1" "$2" "$3" "${4:-}" + TELEMETRY_ERRINFO="${_EH_ACTIVE_LOG}.errinfo" + fi post_update_to_api "failed" "$1" 2>/dev/null || true fi } @@ -424,16 +291,22 @@ _eh_resolve_log() { } # ------------------------------------------------------------------------------ -# _eh_print_log_tail() - the last 20 lines of the log +# _eh_print_log_tail - what the failing step printed, else the last 20 lines # # stderr on purpose: the ERR trap can fire inside a $(...) capture, which would # otherwise swallow this as the captured value. # ------------------------------------------------------------------------------ _eh_print_log_tail() { - local log="$1" + local log="$1" out="" [[ -n "$log" && -s "$log" ]] || return 0 - echo -e "\n${TAB}--- Last 20 lines of log ---" >&2 - tail -n 20 "$log" >&2 + declare -f _tm_focus >/dev/null 2>&1 && out="$(_tm_focus <"$log" | cut -c1-400 | tail -n 25)" + if [[ -n "$out" ]]; then + echo -e "\n${TAB}--- Output of the failing step ---" >&2 + printf '%s\n' "$out" >&2 + else + echo -e "\n${TAB}--- Last 20 lines of log ---" >&2 + tail -n 20 "$log" >&2 + fi echo -e "${TAB}-----------------------------------\n" >&2 } @@ -650,36 +523,53 @@ _eh_offer_container_removal() { fi } +# _eh_source_line - a source line's text, when it can be read again +_eh_source_line() { + local src="$1" line="$2" text="" + [[ "$line" =~ ^[0-9]+$ ]] || return 0 + if [[ -f "$src" && -r "$src" ]]; then + text="$(sed -n "${line}p" "$src" 2>/dev/null)" + elif [[ -n "${BASH_EXECUTION_STRING:-}" && (-z "$src" || "$src" == "main" || "$src" == "bash" || "$src" == "environment") ]]; then + text="$(sed -n "${line}p" <<<"$BASH_EXECUTION_STRING")" + fi + text="${text//\$STD /}" + text="${text#"${text%%[![:space:]]*}"}" + printf '%s' "$text" +} + # ------------------------------------------------------------------------------ # error_handler() # # ERR trap handler: report the failure once, explain it as well as we can, and -# exit with the original code. The steps are in _eh_* above; this is the order -# they run in. +# exit with the original code. # -# The first three locals stay here rather than moving into a helper: -# BASH_LINENO[0] is the caller's line only at this stack depth. +# The locals at the top stay here: BASH_LINENO[0], FUNCNAME[1] and +# BASH_SOURCE[1] describe the failing command only at this stack depth. # ------------------------------------------------------------------------------ error_handler() { local exit_code=${1:-$?} local command=${2:-${BASH_COMMAND:-unknown}} local line_number=${BASH_LINENO[0]:-unknown} + local func="${FUNCNAME[1]:-}" src="${BASH_SOURCE[1]:-}" command="${command//\$STD/}" + command="${command#"${command%%[![:space:]]*}"}" - # silent() knows the real failing command; the trap only sees the wrapper. - # Its record outlives a failure the caller handled, so it only counts for - # the line it came from; otherwise its capture would be sent for this one. - local from_silent=0 + # silent() knows the real failing command; the trap only sees the wrapper, + # or the "return N" of a helper that handled the failure and passed it up. + local capture="" if [[ -n "${_SILENT_FAILED_RC:-}" ]]; then if [[ "${_SILENT_FAILED_LINE:-}" == "$line_number" ]]; then exit_code="$_SILENT_FAILED_RC" command="$_SILENT_FAILED_CMD" - from_silent=1 + capture="${_SILENT_FAILED_LOG:-}.errinfo" + elif [[ "$command" =~ ^(return|exit)([[:space:]]|$) ]]; then + command="$_SILENT_FAILED_CMD" + line_number="$_SILENT_FAILED_LINE" + capture="${_SILENT_FAILED_LOG:-}.errinfo" + func="$(sed -n 's/^FUNCTION=//p' "$capture" 2>/dev/null | head -n1)" else - if [[ -n "${_SILENT_FAILED_LOG:-}" ]]; then - rm -f "${_SILENT_FAILED_LOG}.errinfo" 2>/dev/null - fi + [[ -n "${_SILENT_FAILED_LOG:-}" ]] && rm -f "${_SILENT_FAILED_LOG}.errinfo" 2>/dev/null unset _SILENT_FAILED_LOG fi unset _SILENT_FAILED_RC _SILENT_FAILED_CMD _SILENT_FAILED_LINE @@ -688,16 +578,22 @@ error_handler() { [[ "$exit_code" -eq 0 ]] && return 0 # set -E hands the ERR trap (which passes no arguments) to $(...) and ( ) too. - # The calling shell fails on the same error and reports it, so reporting here - # as well printed it twice. + # The calling shell fails on the same error and reports it. if ((BASH_SUBSHELL > 0 && $# == 0)); then exit "$exit_code" fi - # Telemetry reads these for the "where" + # A helper's "return N" names nothing; the call on that line is what failed. + if [[ -z "$capture" && "$command" =~ ^(return|exit)([[:space:]]|$) ]]; then + local called + called="$(_eh_source_line "$src" "$line_number")" + [[ -n "$called" ]] && command="$called" + fi + FAILED_COMMAND="$command" FAILED_LINE="$line_number" - export FAILED_COMMAND FAILED_LINE + FAILED_FUNCTION="$func" + export FAILED_COMMAND FAILED_LINE FAILED_FUNCTION # Before any output, or the spinner overwrites it declare -f stop_spinner >/dev/null 2>&1 && { stop_spinner 2>/dev/null || true; } @@ -706,8 +602,10 @@ error_handler() { local explanation explanation="$(_eh_explanation "$exit_code" "$command")" - _eh_report "$exit_code" "$command" "$line_number" + _eh_resolve_log + _eh_report "$exit_code" "$command" "$line_number" "$capture" + _EH_REPORTING=1 if declare -f msg_error >/dev/null 2>&1; then msg_error "in line ${line_number}: exit code ${exit_code} (${explanation}): while executing command ${command}" else @@ -716,10 +614,8 @@ error_handler() { _eh_write_debug_log "$exit_code" "$command" "$line_number" "$explanation" - _eh_resolve_log - # silent() captured exactly this command's output; the raw log tail is the fallback. - if ((from_silent)) && [[ -s "${_EH_ACTIVE_LOG}.errinfo" ]]; then - _eh_print_failed_output "${_EH_ACTIVE_LOG}.errinfo" + if [[ -n "$capture" && -s "$capture" ]]; then + _eh_print_failed_output "$capture" else _eh_print_log_tail "$_EH_ACTIVE_LOG" fi diff --git a/tests/exit-code-hints.sh b/tests/exit-code-hints.sh index 98b1a02..8e428c3 100644 --- a/tests/exit-code-hints.sh +++ b/tests/exit-code-hints.sh @@ -3,10 +3,11 @@ set -uo pipefail CORE_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")/.." && pwd)" eval "$(awk '/^(explain_exit_code|categorize_error)[(][)] [{]/,/^}/' "$CORE_DIR/api/exitcodes.func")" -eval "$(awk '/^_eh_(hint_from_log|explanation|tools_for|command_is)[(][)] [{]/,/^}/' "$CORE_DIR/core/error_handler.func")" -eval "$(awk '/^(_tm_explain|build_error_string)[(][)] [{]/,/^}/' "$CORE_DIR/api/errorlog.func")" +eval "$(awk '/^_eh_(hint_from_log|explanation|tools_for|command_is|command_word)[(][)] [{]/,/^}/' "$CORE_DIR/core/error_handler.func")" +eval "$(awk '/^(_tm_explain|_tm_one_line|_tm_error_context|_tm_format_error|build_error_string)[(][)] [{]/,/^}/' "$CORE_DIR/api/errorlog.func")" _tm_find_errinfo() { return 1; } get_error_log() { :; } +unset CS_STEP CS_STEP_DONE CS_ERROR_MSG FAILED_FUNCTION TEST_DIR="$(mktemp -d)" trap 'rm -rf -- "$TEST_DIR"' EXIT @@ -27,24 +28,33 @@ expect() { # Exit status 1 is the command's own verdict; errno 1 (EPERM) is something else. expect "exit 1 is not explained as EPERM" 0 "$(explain_exit_code 1 | grep -c 'Operation not permitted')" -expect "the container fallback table agrees" 0 "$(grep -E '^ *1[)] echo' "$CORE_DIR/core/error_handler.func" | grep -c 'Operation not permitted')" +expect "no table entry for 1-3 asks the reader to look elsewhere" 0 "$(for c in 1 2 3; do explain_exit_code "$c"; done | grep -ci 'says why')" -# A tool-specific meaning holds only for that tool; everything else gets the plain status. -expect "cargo 101 is not an APT error" "Command failed with exit status 101" "$(_eh_explanation 101 'cargo build --release')" +# A tool-specific meaning holds only for that tool; everything else names the program. +expect "cargo 101 is not an APT error" "cargo exited with status 101" "$(_eh_explanation 101 'cargo build --release')" expect "apt-get 101 keeps the APT text" APT "$(_eh_explanation 101 'apt-get install -y jq' | cut -d: -f1)" -expect "a core wrapper returning 7 is not curl" "Command failed with exit status 7" "$(_eh_explanation 7 'fetch_and_deploy_gh_release app owner/repo')" +expect "a core wrapper returning 7 is not curl" "fetch_and_deploy_gh_release exited with status 7" "$(_eh_explanation 7 'fetch_and_deploy_gh_release app owner/repo')" expect "curl 7 with a path keeps the curl text" curl "$(_eh_explanation 7 '/usr/bin/curl -fsSL https://x' | cut -d: -f1)" expect "git 128 is a git fatal error" git "$(_eh_explanation 128 'git clone https://x' | cut -d: -f1)" -expect "pnpm 128 is not" "Command failed with exit status 128" "$(_eh_explanation 128 'pnpm build')" +expect "pnpm 128 is not" "pnpm exited with status 128" "$(_eh_explanation 128 'pnpm build')" expect "node 243 keeps the Node text" Node.js "$(_eh_explanation 243 'node server.js' | cut -d: -f1)" -expect "python 243 does not" "Command failed with exit status 243" "$(_eh_explanation 243 'python3 app.py')" +expect "python 243 does not" "python3 exited with status 243" "$(_eh_explanation 243 'python3 app.py')" expect "core codes stay as they are" Proxmox "$(_eh_explanation 209 '' | cut -d: -f1)" expect "unprefixed codes stay as they are" "Command not found" "$(_eh_explanation 127 'foo')" expect "systemctl 5 is a missing unit" "Systemd: unit not found" "$(_eh_explanation 5 'systemctl start portainer')" +expect "exit 1 names the program" "uv exited with status 1" "$(_eh_explanation 1 'uv run -- python manage.py migrate')" +expect "assignments and \$STD are skipped" "npm exited with status 1" "$(_eh_explanation 1 'NODE_ENV=production $STD /usr/bin/npm ci')" +expect "grep without a match" "grep found no match" "$(_eh_explanation 1 'grep -q foo /etc/hosts')" +expect "arithmetic that evaluates to 0" "Arithmetic expression evaluated to 0" "$(_eh_explanation 1 '((attempt++))')" +expect "a failed test" "Test condition was false" "$(_eh_explanation 1 '[[ -f /opt/app/.env ]]')" +expect "a command substitution" "Command substitution exited with status 1" "$(_eh_explanation 1 'RELEASE=$(curl -fsSL "$URL" | grep -oP x | head -n1)')" +expect "an unresolved return" "Exit status 7" "$(_eh_explanation 7 'return 7')" # The telemetry summary goes through the same guard when the command is known. expect "the summary does not call systemctl 5 a proxy error" "exit_code=5 | Systemd: unit not found | at line 76: systemctl start portainer" "$(FAILED_COMMAND='systemctl start portainer' FAILED_LINE=76 build_error_string 5)" -expect "pct exec 255 is not a DPKG error" "exit_code=255 | Command failed with exit status 255 | at line 12: pct exec 100 -- ip a" "$(FAILED_COMMAND='pct exec 100 -- ip a' FAILED_LINE=12 build_error_string 255)" +expect "pct exec 255 is not a DPKG error" "exit_code=255 | pct exited with status 255 | at line 12: pct exec 100 -- ip a" "$(FAILED_COMMAND='pct exec 100 -- ip a' FAILED_LINE=12 build_error_string 255)" +expect "step and function join the header" "exit_code=7 | Exit status 7 | step: Setting up Grafana Repository | in setup_deb822_repo | at line 24: return 7" "$(CS_STEP='Setting up Grafana Repository' FAILED_FUNCTION=setup_deb822_repo FAILED_COMMAND='return 7' FAILED_LINE=24 build_error_string 7)" +expect "a finished step is named as such" "exit_code=64 | Missing or invalid input (a required setting was not given) | step: after Updated Container OS" "$(CS_STEP_DONE='Updated Container OS' FAILED_COMMAND= build_error_string 64)" expect "apt 100 keeps the APT text" APT "$(FAILED_COMMAND='apt install -y grafana' FAILED_LINE=31 build_error_string 100 | cut -d'|' -f2 | cut -d: -f1 | tr -d ' ')" expect "without a command the table stands" "exit_code=255 | DPKG: Fatal internal error" "$(FAILED_COMMAND= build_error_string 255)" diff --git a/tests/stale-silent-record.sh b/tests/stale-silent-record.sh index fb6e5e8..d953646 100644 --- a/tests/stale-silent-record.sh +++ b/tests/stale-silent-record.sh @@ -5,7 +5,7 @@ set -uo pipefail CORE_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")/.." && pwd)" -eval "$(awk '/^error_handler[(][)] [{]/,/^}/' "$CORE_DIR/core/error_handler.func")" +eval "$(awk '/^(error_handler|_eh_source_line|_eh_resolve_log)[(][)] [{]/,/^}/' "$CORE_DIR/core/error_handler.func")" TEST_DIR="$(mktemp -d)" trap 'rm -rf -- "$TEST_DIR"' EXIT @@ -45,5 +45,20 @@ line=$LINENO; handled_failure "$line"; out="$(error_handler 1 'silent apt instal expect "silent's record is used for its own line" 1 "$(grep -c 'REPORT 100|apt install -y intel-basekit|' <<<"$out")" expect "its capture is kept" 1 "$(ls "$ERRINFO" 2>/dev/null | wc -l)" +# A helper that handled it and passed it up with "return": that command is still what broke. +handled_failure 5 +out="$(error_handler 100 'return 100')" +expect "a passed-up failure reports silent's command and line" 1 "$(grep -c 'REPORT 100|apt install -y intel-basekit|5' <<<"$out")" +expect "and keeps its capture" 1 "$(ls "$ERRINFO" 2>/dev/null | wc -l)" + +# Without a record, "return N" is replaced by the call on that source line. +printf '%s\n' 'setup_thing() {' ' fetch_release foo' '}' >"$TEST_DIR/lib.sh" +unset _SILENT_FAILED_RC +out="$(BASH_EXECUTION_STRING='' _eh_source_line "$TEST_DIR/lib.sh" 2)" +expect "the source line names the failing call" "fetch_release foo" "$out" +out="$(BASH_EXECUTION_STRING=$'line one\n $STD setup_uv' _eh_source_line "" 2)" +expect "a bash -c script is read from BASH_EXECUTION_STRING" "setup_uv" "$out" +expect "an unreadable source gives nothing" "" "$(BASH_EXECUTION_STRING='' _eh_source_line /dev/stdin 1)" + echo "$passed passed, $failed failed" ((failed == 0)) diff --git a/tests/telemetry-trace.sh b/tests/telemetry-trace.sh new file mode 100644 index 0000000..fcae9bc --- /dev/null +++ b/tests/telemetry-trace.sh @@ -0,0 +1,127 @@ +#!/usr/bin/env bash +set -uo pipefail + +CORE_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")/.." && pwd)" +REPO_SOURCE=ProxmoxVE +for part in exitcodes errorlog sysinfo telemetry; do + # shellcheck disable=SC1090 + source "$CORE_DIR/api/${part}.func" +done +eval "$(awk '/^_eh_(explanation|tools_for|command_is|command_word)[(][)] [{]/,/^}/' "$CORE_DIR/core/error_handler.func")" +TELEMETRY_PAYLOAD_VERSION=3 TELEMETRY_TIMEOUT=5 STATUS_TIMEOUT=10 + +TEST_DIR="$(mktemp -d)" +trap 'rm -rf -- "$TEST_DIR"' EXIT +LOG="$TEST_DIR/install.log" +SENT="$TEST_DIR/sent.json" +passed=0 failed=0 + +expect() { + if [[ "$2" == "$3" ]]; then + echo "PASS $1" + passed=$((passed + 1)) + else + echo "FAIL $1: expected <$2>, got <$3>" >&2 + failed=$((failed + 1)) + fi +} +json_field() { + if command -v jq >/dev/null 2>&1; then + jq -r --arg k "$2" '.[$k] | tostring' "$1" + else + python3 -c 'import json,sys; v=json.load(open(sys.argv[1]))[sys.argv[2]]; print(v if not isinstance(v,bool) else str(v).lower())' "$1" "$2" + fi +} +reset() { + : >"$LOG" + rm -f "$SENT" "$TEST_DIR"/*.errinfo + unset TELEMETRY_ERRINFO FAILED_COMMAND FAILED_LINE FAILED_FUNCTION CS_STEP CS_STEP_DONE CS_ERROR_MSG ERROR_CATEGORY_OVERRIDE + unset TM_ERR_CODE TM_ERR_EXPLANATION + POST_TO_API_DONE=true POST_UPDATE_DONE=false +} +_tm_send() { printf '%s' "$1" >"$SENT"; } +telemetry_collect_sysinfo() { :; } +DIAGNOSTICS=yes RANDOM_UUID=00000000-0000-4000-8000-000000000000 SESSION_ID=test NSAPP=demo +BUILD_LOG="$LOG" INSTALL_LOG="$TEST_DIR/none.log" + +# --- noise filter --- +printf '%s\n' \ + 'Get:1 http://deb.debian.org/debian trixie InRelease [140 kB]' \ + 'Setting up libssl3t64:amd64 (3.5.1-1) ...' \ + 'update-alternatives: using /usr/bin/node to provide /usr/bin/js (js) in auto mode' \ + ' 0K ........ ........ ........ ........ 25% 8.29M 11s' \ + '+ umask 022' \ + ' WARNING: You have not turned on protection against thin pools running out of space.' \ + 'E: Unable to locate package foo' \ + '[2026-01-01 10:00:00] Setup uv 0.9.5 from 192.168.1.101' >"$LOG" +out="$(_tm_clean_log <"$LOG")" +expect "progress chatter is dropped" 2 "$(wc -l <<<"$out" | tr -d ' ')" +expect "the apt error survives" 1 "$(grep -c '^E: Unable to locate package foo$' <<<"$out")" +expect "versions survive, addresses do not" "[2026-01-01 10:00:00] Setup uv 0.9.5 from 192.x.x.x" "$(tail -n1 <<<"$out")" + +# --- step scoping --- +printf '%s\n' '[2026-01-01 10:00:00] [INFO] Installing Dependencies' 'old output' \ + '[2026-01-01 10:00:05] [OK] Installed Dependencies' \ + '[2026-01-01 10:00:06] [INFO] Setting up Demo' 'curl: (22) The requested URL returned error: 404' >"$LOG" +expect "only the failing step is kept" "[2026-01-01 10:00:06] [INFO] Setting up Demo|curl: (22) The requested URL returned error: 404" "$(_tm_focus <"$LOG" | paste -sd'|')" + +# --- a container failure, read by the host --- +reset +printf '%s\n' 'EXIT_CODE=7' 'LINE=24' 'COMMAND=setup_uv' 'FUNCTION=' 'STEP=Setup uv' \ + 'MESSAGE=Failed to download uv from https://github.com/astral-sh/uv/releases/x.tar.gz' 'PHASE=container' \ + '--- OUTPUT ---' '[2026-01-01 10:00:06] [INFO] Setup uv' 'curl: (7) Failed to connect to github.com port 443' >"$TEST_DIR/ct.errinfo" +TELEMETRY_ERRINFO="$TEST_DIR/ct.errinfo" +CS_ERROR_MSG="Installation failed in container 100 (exit code: 7)" CS_STEP="Starting install" +post_update_to_api failed 7 +expect "the container's message wins over the host's" "Failed to download uv from https://github.com/astral-sh/uv/releases/x.tar.gz" "$(json_field "$SENT" error_message)" +expect "the container's step" "Setup uv" "$(json_field "$SENT" error_step)" +expect "phase" container "$(json_field "$SENT" error_phase)" +expect "failed command" setup_uv "$(json_field "$SENT" failed_command)" +expect "payload version" 3 "$(json_field "$SENT" payload_version)" +expect "header" "exit_code=7 | setup_uv exited with status 7 | step: Setup uv | at line 24: setup_uv" "$(json_field "$SENT" error | head -n1)" + +# --- a capture for an earlier failure is not used --- +reset +printf '%s\n' 'EXIT_CODE=100' 'LINE=3' 'COMMAND=apt-get install -y foo' 'PHASE=host' '--- OUTPUT ---' 'E: old' >"$LOG.errinfo" +printf '%s\n' '[2026-01-01 10:00:00] [INFO] Creating container' 'unable to create CT 101 - storage full' >"$LOG" +CS_ERROR_MSG="Container creation failed" CS_STEP="Creating container" +post_update_to_api failed 209 +expect "mismatched capture ignored" 209 "$(json_field "$SENT" exit_code)" +expect "host message" "Container creation failed" "$(json_field "$SENT" error_message)" +expect "host phase" host "$(json_field "$SENT" error_phase)" +expect "step output instead" 1 "$(json_field "$SENT" error | grep -c 'storage full')" + +# --- status mapping --- +reset +post_update_to_api failed 130 +expect "Ctrl-C is an abort" aborted "$(json_field "$SENT" status)" +expect "an abort sends no message" "" "$(json_field "$SENT" error_message)" +reset +post_update_to_api done none +expect "done is success" success "$(json_field "$SENT" status)" +expect "success carries no error" "" "$(json_field "$SENT" error)" +reset +post_update_to_api failed "" +expect "a lost code is 199" 199 "$(json_field "$SENT" exit_code)" +reset +POST_UPDATE_DONE=true +post_update_to_api failed 1 +expect "one terminal event per execution" no "$([[ -f "$SENT" ]] && echo yes || echo no)" + +# --- JSON stays valid with awkward text --- +reset +CS_ERROR_MSG=$'quote " backslash \\ tab \t done' CS_STEP='Step "x"' +printf '%s\n' '[2026-01-01 10:00:00] [INFO] Step "x"' 'line with "quotes"' >"$LOG" +post_update_to_api failed 1 +expect "message with quotes and backslashes round-trips" 'quote " backslash \ tab done' "$(json_field "$SENT" error_message)" + +# --- tools and add-ons carry the same fields --- +reset +CS_ERROR_MSG="No LXC containers found" CS_STEP="Scanning containers" +post_tool_to_api demo-tool failed 234 +expect "tool failures stay failures" failed "$(json_field "$SENT" status)" +expect "tool type" pve "$(json_field "$SENT" type)" +expect "tool message" "No LXC containers found" "$(json_field "$SENT" error_message)" + +printf '%s passed, %s failed\n' "$passed" "$failed" +((failed == 0)) From 864614993ca14ea6abb1a704d740ed335302f2e8 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:09:00 +0100 Subject: [PATCH 03/11] Load the engine from the container's prefetched copy The container now also loads the exit code table and the log filter, so error_handler drops its own copy of the table. Sourcing the files by path lets the error handler read a failing line back. --- lib/tools.func | 8 ++++++-- lxc/install.func | 42 +++++++++++++++++++++++++----------------- 2 files changed, 31 insertions(+), 19 deletions(-) diff --git a/lib/tools.func b/lib/tools.func index 2cdc04b..cf82aaf 100644 --- a/lib/tools.func +++ b/lib/tools.func @@ -66,8 +66,12 @@ _tools_source_part() { return fi - # Inside the container there is no resolver: fall back to the engine base, - # which the backends export alongside the scripts base. + # Inside the container: install.func's prefetched copy, else the engine base. + if [[ -n "${COMMUNITY_SCRIPTS_CORE_DIR:-}" && -s "${COMMUNITY_SCRIPTS_CORE_DIR}/lib/${part}.func" ]]; then + # shellcheck disable=SC1090 + source "${COMMUNITY_SCRIPTS_CORE_DIR}/lib/${part}.func" + return + fi local base="${COMMUNITY_SCRIPTS_CORE_URL:-https://raw.githubusercontent.com/community-scripts/core/main}" if command -v curl >/dev/null 2>&1; then # shellcheck disable=SC1090 diff --git a/lxc/install.func b/lxc/install.func index 38a3792..6ebbdda 100644 --- a/lxc/install.func +++ b/lxc/install.func @@ -78,11 +78,11 @@ _cs_curl_retry() { return "$rc" } -# The engine reaches a container in nine pieces. The host's prefetch cannot -# help here — a container has its own filesystem — so fetch them concurrently -# on this side too. verify-split-files.yml checks the list is complete. +# The host's prefetch cannot reach a container's filesystem, so fetch the +# engine concurrently on this side too. verify-split-files.yml checks the list. _CS_CT_ENGINE_FILES=( core/core.func core/error_handler.func + api/exitcodes.func api/errorlog.func lib/tools.func lib/alpine.func lib/db.func lib/forge.func lib/hwaccel.func lib/runtime.func lib/system.func ) @@ -110,7 +110,7 @@ _cs_ct_prefetch_engine() { local args=() rel core_base core_base="${COMMUNITY_SCRIPTS_CORE_URL:-https://raw.githubusercontent.com/community-scripts/core/main}" - mkdir -p "${dir}/core" "${dir}/lib" 2>/dev/null || true + mkdir -p "${dir}/core" "${dir}/api" "${dir}/lib" 2>/dev/null || true for rel in "${_CS_CT_ENGINE_FILES[@]}"; do args+=(-o "${dir}/${rel}" "${core_base}/${rel}") done @@ -313,9 +313,14 @@ _bootstrap_die() { _bootstrap_source() { local rel="${1:?func path}" probe="${2:?probe function}" content - content="$(_cs_engine_read "$rel")" && [[ -n "$content" ]] || - _bootstrap_die "Failed to download ${rel}" - source /dev/stdin <<<"$content" + # From the file when prefetched, so the error handler can read a failing line back. + if [[ -n "${COMMUNITY_SCRIPTS_CORE_DIR:-}" && -s "${COMMUNITY_SCRIPTS_CORE_DIR}/${rel}" ]]; then + source "${COMMUNITY_SCRIPTS_CORE_DIR}/${rel}" + else + content="$(_cs_engine_read "$rel")" && [[ -n "$content" ]] || + _bootstrap_die "Failed to download ${rel}" + source /dev/stdin <<<"$content" + fi declare -f "$probe" >/dev/null 2>&1 || _bootstrap_die "${rel} loaded but incomplete (missing ${probe})" } @@ -375,6 +380,8 @@ _bootstrap() { # Source core functions _cs_ct_prefetch_engine || true _bootstrap_source core/core.func load_functions + _bootstrap_source api/exitcodes.func explain_exit_code + _bootstrap_source api/errorlog.func _tm_focus _bootstrap_source core/error_handler.func catch_errors # The dev helpers are worth a round trip only when a flag is set: core.func's # timing hooks no-op without them, and error_handler's exit path asks for the @@ -419,13 +426,10 @@ post_progress_to_api() { local progress_status="${1:-configuring}" # The only telemetry a container sends; terminal statuses come from the host. - # execution_id and repo attribution let the server correlate these rows. - # TELEMETRY_URL rather than the literal address: hardcoding it meant an - # endpoint override worked everywhere except inside the container. curl -fsS -m 5 -X POST "${TELEMETRY_URL:-https://telemetry.community-scripts.org/telemetry}" \ -H "Content-Type: application/json" \ - -A "community-scripts-core/${TELEMETRY_PAYLOAD_VERSION:-2}" \ - -d "{\"payload_version\":${TELEMETRY_PAYLOAD_VERSION:-2},\"random_id\":\"${RANDOM_UUID}\",\"execution_id\":\"${EXECUTION_ID:-${RANDOM_UUID}}\",\"type\":\"lxc\",\"nsapp\":\"${app:-unknown}\",\"status\":\"${progress_status}\",\"platform\":\"${TELEMETRY_PLATFORM:-}\",\"repo_source\":\"${REPO_SOURCE:-}\",\"repo_slug\":\"${REPO_SLUG:-}\"}" &>/dev/null || true + -A "community-scripts-core/${TELEMETRY_PAYLOAD_VERSION:-3}" \ + -d "{\"payload_version\":${TELEMETRY_PAYLOAD_VERSION:-3},\"random_id\":\"${RANDOM_UUID}\",\"execution_id\":\"${EXECUTION_ID:-${RANDOM_UUID}}\",\"type\":\"lxc\",\"nsapp\":\"${app:-unknown}\",\"status\":\"${progress_status}\",\"platform\":\"${TELEMETRY_PLATFORM:-}\",\"repo_source\":\"${REPO_SOURCE:-}\",\"repo_slug\":\"${REPO_SLUG:-}\"}" &>/dev/null || true } # ============================================================================== @@ -1416,12 +1420,16 @@ EOF alpine) tools_name="lib/alpine.func" ;; *) tools_name="lib/tools.func" ;; esac - tools_content=$(_cs_engine_read "${tools_name}") - if [[ -z "$tools_content" ]]; then - msg_error "Failed to download ${tools_name}" - exit 115 + if [[ -n "${COMMUNITY_SCRIPTS_CORE_DIR:-}" && -s "${COMMUNITY_SCRIPTS_CORE_DIR}/${tools_name}" ]]; then + source "${COMMUNITY_SCRIPTS_CORE_DIR}/${tools_name}" + else + tools_content=$(_cs_engine_read "${tools_name}") + if [[ -z "$tools_content" ]]; then + msg_error "Failed to download ${tools_name}" + exit 115 + fi + source /dev/stdin <<<"$tools_content" fi - source /dev/stdin <<<"$tools_content" if ! declare -f fetch_and_deploy_gh_release >/dev/null 2>&1; then msg_error "tools.func loaded but incomplete — missing expected functions" exit 115 From b652930ad997df840280d586cf6c1ddd8fc6b108 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:09:01 +0100 Subject: [PATCH 04/11] Pass the telemetry endpoint into the container and close the detached-install race A detached install that wrote .done just before exiting was reported as a lost exit code. The recovery menu checks the failing step's output instead of the whole run. Incus no longer opts a container into telemetry when the host value is unset, and a missing exit code is 199 on both hosts. --- incus/backend.func | 9 ++++++--- pve/backend.func | 41 ++++++++++++++++++++++++++++------------- 2 files changed, 34 insertions(+), 16 deletions(-) diff --git a/incus/backend.func b/incus/backend.func index 8585f7f..f3f9d4a 100644 --- a/incus/backend.func +++ b/incus/backend.func @@ -1170,7 +1170,8 @@ mkfifo ${_base}.in" >>"${LOGFILE:-$INCUS_BUILD_LOG}" 2>&1 if [[ -n "${SESSION_ID:-}" ]]; then local error_flag="/root/.install-${SESSION_ID}.failed" if incus_ct_exec test -f "$error_flag" 2>/dev/null; then - install_exit_code=$(incus_ct_exec cat "$error_flag" 2>/dev/null || echo "1") + install_exit_code=$(incus_ct_exec cat "$error_flag" 2>/dev/null | tr -d '[:space:]') || true + [[ "$install_exit_code" =~ ^[0-9]+$ ]] || install_exit_code=199 incus_ct_exec rm -f "$error_flag" 2>/dev/null || true fi fi @@ -1187,7 +1188,7 @@ mkfifo ${_base}.in" >>"${LOGFILE:-$INCUS_BUILD_LOG}" 2>&1 msg_error "Install script stopped before it finished - nothing reported it" [[ "${_CS_HANGUP:-}" == "1" ]] && msg_custom "ℹ️" "${YW}" "The console was closed; the install ran on detached, so look at its log for the reason" msg_custom "ℹ️" "${YW}" "Output: incus exec ${CT_NAME} -- tail -50 /root/.install-${SESSION_ID}.log" - install_exit_code=1 + install_exit_code=199 fi fi incus_ct_exec rm -f "${_base}.sh" "${_base}.run" "${_base}.watch" "${_base}.in" "${_base}.pid" "${_base}.out" >/dev/null 2>&1 || true @@ -1472,7 +1473,7 @@ incus_run_install_script_with_recovery() { # everything the install side reads is passed here, quoted with %q. _incus_build_install_env() { local -a env=( - DIAGNOSTICS="${DIAGNOSTICS:-yes}" + DIAGNOSTICS="${DIAGNOSTICS:-no}" RANDOM_UUID="${RANDOM_UUID}" EXECUTION_ID="${EXECUTION_ID}" SESSION_ID="${SESSION_ID}" @@ -1504,6 +1505,8 @@ _incus_build_install_env() { REPO_SOURCE="${REPO_SOURCE:-}" REPO_SLUG="${REPO_SLUG:-}" TELEMETRY_PLATFORM="incus" + TELEMETRY_URL="${TELEMETRY_URL:-}" + TELEMETRY_PAYLOAD_VERSION="${TELEMETRY_PAYLOAD_VERSION:-}" CS_ANIMATION_OK="${_incus_tty_out:-0}" CS_STDIN_OK="${_incus_tty_in:-0}" ) diff --git a/pve/backend.func b/pve/backend.func index e78939a..f174779 100644 --- a/pve/backend.func +++ b/pve/backend.func @@ -211,6 +211,9 @@ _pve_wait_for_detached_install() { fi pid="$(pct exec "$CTID" -- cat "${base}.pid" 2>/dev/null | tr -d '[:space:]')" if [[ "$pid" =~ ^[0-9]+$ ]] && ! pct exec "$CTID" -- kill -0 "$pid" 2>/dev/null; then + # It may have written its marker between the checks above and exiting. + pct exec "$CTID" -- test -f "${base}.failed" 2>/dev/null && return 1 + pct exec "$CTID" -- test -f "${base}.done" 2>/dev/null && return 0 echo "[WARN] Install process ${pid} is gone without reporting; processes left in the container:" pct exec "$CTID" -- ps -eo pid,ppid,stat,etime,cmd 2>/dev/null | head -n 40 return 199 @@ -510,6 +513,7 @@ build_container() { export REPO_SLUG="${REPO_SLUG:-}" # Virtualization platform for telemetry (container has no pveversion) export TELEMETRY_PLATFORM="pve" + export TELEMETRY_URL TELEMETRY_PAYLOAD_VERSION export CACHER="$APT_CACHER" export CACHER_IP="$APT_CACHER_IP" if [[ -n "${HTTP_PROXY:-}" ]]; then @@ -1517,6 +1521,16 @@ $_install_script" fi fi + # The checks below look at what the failing step printed, not the whole run. + local failure_log="/tmp/.failure-${SESSION_ID:-$$}.log" + if [[ -s "${TELEMETRY_ERRINFO:-}" ]]; then + awk 'f{print} /^--- OUTPUT ---$/{f=1}' "$TELEMETRY_ERRINFO" >"$failure_log" 2>/dev/null + elif [[ -s "$combined_log" ]] && declare -f _tm_focus >/dev/null 2>&1; then + _tm_focus <"$combined_log" >"$failure_log" 2>/dev/null + else + cp "$combined_log" "$failure_log" 2>/dev/null + fi + set +Eeuo pipefail trap - ERR @@ -1526,20 +1540,20 @@ $_install_script" local is_cmd_not_found=false local is_disk_full=false - if [[ $install_exit_code -eq 1 && -f "$combined_log" ]]; then - if grep -qiE 'E: Unable to|E: Package|E: Failed to fetch|dpkg.*error|broken packages|unmet dependencies|dpkg --configure -a' "$combined_log"; then + if [[ $install_exit_code -eq 1 && -f "$failure_log" ]]; then + if grep -qiE 'E: Unable to|E: Package|E: Failed to fetch|dpkg.*error|broken packages|unmet dependencies|dpkg --configure -a' "$failure_log"; then is_apt_issue=true fi - if grep -qiE 'Cannot allocate memory|Out of memory|oom-killer|Killed process|JavaScript heap' "$combined_log"; then + if grep -qiE 'Cannot allocate memory|Out of memory|oom-killer|Killed process|JavaScript heap' "$failure_log"; then is_oom=true fi - if grep -qiE 'Could not resolve|DNS resolution failed|Connection refused|Network is unreachable|No route to host|Temporary failure resolving|Failed to fetch' "$combined_log"; then + if grep -qiE 'Could not resolve|DNS resolution failed|Connection refused|Network is unreachable|No route to host|Temporary failure resolving|Failed to fetch' "$failure_log"; then is_network_issue=true fi - if grep -qiE ': command not found|No such file or directory.*/s?bin/' "$combined_log"; then + if grep -qiE ': command not found|No such file or directory.*/s?bin/' "$failure_log"; then is_cmd_not_found=true fi - if grep -qiE 'ENOSPC|no space left on device|Disk quota exceeded|errno -28' "$combined_log"; then + if grep -qiE 'ENOSPC|no space left on device|Disk quota exceeded|errno -28' "$failure_log"; then is_disk_full=true fi fi @@ -1606,7 +1620,7 @@ $_install_script" fi ;; 255) - if [[ -f "$combined_log" ]] && grep -qiE 'dpkg|apt-get|apt\.conf|broken packages|unmet dependencies|E: Sub-process|E: Failed' "$combined_log"; then + if [[ -f "$failure_log" ]] && grep -qiE 'dpkg|apt-get|apt\.conf|broken packages|unmet dependencies|E: Sub-process|E: Failed' "$failure_log"; then is_apt_issue=true fi ;; @@ -1615,7 +1629,7 @@ $_install_script" if [[ $install_exit_code -eq 228 || $install_exit_code -eq 23 ]]; then is_disk_full=true fi - if [[ -f "$combined_log" ]] && grep -qiE 'ENOSPC|no space left on device|No space left on device|Disk quota exceeded|errno -28' "$combined_log"; then + if [[ -f "$failure_log" ]] && grep -qiE 'ENOSPC|no space left on device|No space left on device|Disk quota exceeded|errno -28' "$failure_log"; then is_disk_full=true fi @@ -1626,12 +1640,12 @@ $_install_script" case "$install_exit_code" in 6 | 7 | 22 | 28 | 35 | 52 | 56 | 57 | 75 | 78) is_network_issue=true ;; 100) - if [[ -f "$combined_log" ]] && grep -qiE 'Failed to fetch|Could not resolve|Connection failed|Network is unreachable|Temporary failure resolving' "$combined_log"; then + if [[ -f "$failure_log" ]] && grep -qiE 'Failed to fetch|Could not resolve|Connection failed|Network is unreachable|Temporary failure resolving' "$failure_log"; then is_network_issue=true fi ;; 128) - if [[ -f "$combined_log" ]] && grep -qiE 'RPC failed|early EOF|fetch-pack|HTTP/2 stream|Could not resolve host|Temporary failure resolving|Failed to fetch|Connection reset|Network is unreachable' "$combined_log"; then + if [[ -f "$failure_log" ]] && grep -qiE 'RPC failed|early EOF|fetch-pack|HTTP/2 stream|Could not resolve host|Temporary failure resolving|Failed to fetch|Connection reset|Network is unreachable' "$failure_log"; then is_network_issue=true fi ;; @@ -1662,8 +1676,8 @@ $_install_script" if [[ "$is_cmd_not_found" == true ]]; then local missing_cmd="" - if [[ -f "$combined_log" ]]; then - missing_cmd=$(grep -oiE '[a-zA-Z0-9_.-]+: command not found' "$combined_log" 2>/dev/null | tail -1 | sed 's/: command not found//') || true + if [[ -f "$failure_log" ]]; then + missing_cmd=$(grep -oiE '[a-zA-Z0-9_.-]+: command not found' "$failure_log" 2>/dev/null | tail -1 | sed 's/: command not found//') || true fi if [[ -n "$missing_cmd" ]]; then echo -e "${TAB}${INFO} Missing command: ${GN}${missing_cmd}${CL}" @@ -1846,7 +1860,8 @@ $_install_script" if [[ -n "${SESSION_ID:-}" ]]; then local retry_error_flag="/root/.install-${SESSION_ID}.failed" if pct exec "$CTID" -- test -f "$retry_error_flag" 2>/dev/null; then - apt_retry_code=$(pct exec "$CTID" -- cat "$retry_error_flag" 2>/dev/null || echo "1") + apt_retry_code=$(pct exec "$CTID" -- cat "$retry_error_flag" 2>/dev/null | tr -d '[:space:]') || true + [[ "$apt_retry_code" =~ ^[0-9]+$ ]] || apt_retry_code=199 pct exec "$CTID" -- rm -f "$retry_error_flag" 2>/dev/null || true fi fi From 827b0676e8835ee8a284a4e605d853e19b525335 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:09:02 +0100 Subject: [PATCH 05/11] Give VM runs one log and a failure capture get_active_logfile returned a new file per call, so VM failures carried no output. msg_* now log steps, silent() writes a capture, and the error handlers record command, line and function before reporting. --- pve/vm-core.func | 72 +++++++++++++++++++++++++++++++++++------------- 1 file changed, 53 insertions(+), 19 deletions(-) diff --git a/pve/vm-core.func b/pve/vm-core.func index f7e479f..ada9afd 100644 --- a/pve/vm-core.func +++ b/pve/vm-core.func @@ -71,6 +71,9 @@ SPINNER_MSG="" [[ -n "${_CORE_FUNC_LOADED:-}" ]] && return _CORE_FUNC_LOADED=1 +BUILD_LOG="${BUILD_LOG:-/tmp/cs-vm-$$.log}" +export BUILD_LOG + COMMUNITY_SCRIPTS_URL="${COMMUNITY_SCRIPTS_URL:-https://raw.githubusercontent.com/community-scripts/ProxmoxVE/main}" load_api_functions() { @@ -302,12 +305,12 @@ default_vars() { # - Fallback to /tmp/build-.log if not set # ------------------------------------------------------------------------------ get_active_logfile() { - if [[ -n "${BUILD_LOG:-}" ]]; then - echo "$BUILD_LOG" - else - # Fallback for legacy scripts - echo "/tmp/build-$(date +%Y%m%d_%H%M%S).log" - fi + echo "${BUILD_LOG:-/tmp/cs-vm-$$.log}" +} + +# One log per run: msg_* and silent() write to it, telemetry reads the failing step from it. +_vm_log() { + echo "[$(date '+%Y-%m-%d %H:%M:%S')] $*" >>"$(get_active_logfile)" 2>/dev/null || true } # ------------------------------------------------------------------------------ @@ -329,6 +332,8 @@ silent() { set +Eeuo pipefail trap - ERR + local start_bytes=0 + [[ -f "$logfile" ]] && start_bytes=$(stat -c%s "$logfile" 2>/dev/null || echo 0) "$@" >>"$logfile" 2>&1 local rc=$? @@ -337,9 +342,20 @@ silent() { if [[ $rc -ne 0 ]]; then export _SILENT_FAILED_RC="$rc" _SILENT_FAILED_CMD="$cmd" _SILENT_FAILED_LINE="$caller_line" _SILENT_FAILED_LOG="$logfile" + { + echo "EXIT_CODE=${rc}" + echo "LINE=${caller_line}" + echo "COMMAND=$(printf '%s' "$cmd" | tr '\n' ' ' | head -c 300)" + echo "FUNCTION=${FUNCNAME[1]:-}" + echo "STEP=${CS_STEP:-}" + echo "PHASE=host" + echo "--- OUTPUT ---" + tail -c +"$((start_bytes + 1))" "$logfile" 2>/dev/null | tail -n 200 | head -c 32768 + } >"${logfile}.errinfo" 2>/dev/null || true return "$rc" fi unset _SILENT_FAILED_RC _SILENT_FAILED_CMD _SILENT_FAILED_LINE _SILENT_FAILED_LOG + rm -f "${logfile}.errinfo" 2>/dev/null || true } # The record silent() left behind only counts for the line it came from: a @@ -362,6 +378,19 @@ _vm_show_silent_failure() { unset _SILENT_FAILED_RC _SILENT_FAILED_CMD _SILENT_FAILED_LINE _SILENT_FAILED_LOG } +# _vm_take_silent_failure - 0 and the capture handed to telemetry when silent() failed on that line +_vm_take_silent_failure() { + if [[ -n "${_SILENT_FAILED_RC:-}" && "${_SILENT_FAILED_LINE:-}" == "$1" ]]; then + _SILENT_FAILED_CMD_SEEN="$_SILENT_FAILED_CMD" + [[ -s "${_SILENT_FAILED_LOG:-}.errinfo" ]] && TELEMETRY_ERRINFO="${_SILENT_FAILED_LOG}.errinfo" + _vm_show_silent_failure + return 0 + fi + [[ -n "${_SILENT_FAILED_LOG:-}" ]] && rm -f "${_SILENT_FAILED_LOG}.errinfo" 2>/dev/null + unset _SILENT_FAILED_RC _SILENT_FAILED_CMD _SILENT_FAILED_LINE _SILENT_FAILED_LOG + return 1 +} + # ------------------------------------------------------------------------------ # Performs a curl request with retry logic and inline feedback. # ------------------------------------------------------------------------------ @@ -610,12 +639,15 @@ spinner_guard() { msg_info() { local msg="${1:-Information message}" + CS_STEP="$msg" + CS_ERROR_MSG="" # Only show each message once unless reset if [[ -n "${MSG_INFO_SHOWN["$msg"]+x}" ]]; then return fi MSG_INFO_SHOWN["$msg"]=1 + _vm_log "[INFO] $msg" spinner_guard start_spinner "$msg" @@ -623,21 +655,23 @@ msg_info() { msg_ok() { local msg="${1:-Operation completed successfully}" + CS_STEP_DONE="$msg" + CS_STEP="" + CS_ERROR_MSG="" stop_spinner printf "\r\e[2K%s %b\n" "${CM}" "${GN}${msg}${CL}" >&2 + _vm_log "[OK] $msg" - # Remove from shown messages to allow it to be shown again. - # - # The key has to be the one msg_info stored. It was sanitised here and raw - # there, so the two never matched: nothing was ever removed, and a message - # was suppressed for the rest of the run after its first appearance. + # The key has to be the one msg_info stored. unset 'MSG_INFO_SHOWN['"$msg"']' 2>/dev/null || true } msg_error() { local msg="${1:-An error occurred}" + [[ -z "${CS_ERROR_MSG:-}" && -z "${_EH_REPORTING:-}" ]] && CS_ERROR_MSG="$msg" stop_spinner printf "\r\e[2K%s %b\n" "${CROSS}" "${RD}${msg}${CL}" >&2 + _vm_log "[ERROR] $msg" } msg_warn() { @@ -675,10 +709,10 @@ error_handler() { local line_number="${1:-unknown}" local command="${2:-unknown}" - if [[ -n "${_SILENT_FAILED_RC:-}" && "${_SILENT_FAILED_LINE:-}" == "$line_number" ]]; then - command="$_SILENT_FAILED_CMD" - _vm_show_silent_failure - fi + _EH_REPORTING=1 + _vm_take_silent_failure "$line_number" && command="$_SILENT_FAILED_CMD_SEEN" + FAILED_COMMAND="$command" FAILED_LINE="$line_number" FAILED_FUNCTION="${FUNCNAME[1]:-}" + export FAILED_COMMAND FAILED_LINE FAILED_FUNCTION if declare -f post_update_to_api >/dev/null 2>&1; then post_update_to_api "failed" "$exit_code" @@ -2311,10 +2345,10 @@ vm_mark_created() { vm_post_create_error() { local rc=$? line="${1:-unknown}" cmd="${2:-unknown}" - if [[ -n "${_SILENT_FAILED_RC:-}" && "${_SILENT_FAILED_LINE:-}" == "$line" ]]; then - cmd="$_SILENT_FAILED_CMD" - _vm_show_silent_failure - fi + _EH_REPORTING=1 + _vm_take_silent_failure "$line" && cmd="$_SILENT_FAILED_CMD_SEEN" + FAILED_COMMAND="$cmd" FAILED_LINE="$line" FAILED_FUNCTION="${FUNCNAME[1]:-}" + export FAILED_COMMAND FAILED_LINE FAILED_FUNCTION msg_warn "A step after VM creation failed (line ${line}, exit ${rc}): ${cmd}" msg_warn "VM ${VMID:-?} is left in place -- finish the remaining configuration by hand." declare -f post_update_to_api >/dev/null 2>&1 && post_update_to_api "failed" "$rc" From 6f3c267e71e3530fdf909b841019538ba38a11e9 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:31:42 +0100 Subject: [PATCH 06/11] Keep the ERR trap's explanation free of early returns, and let the container prefetch The new explanation returned from inside case and loop blocks; with errtrace on and the engine sourced from a pipe, bash lost track of its function contexts and the container's failure was never written. lxc-attach also carried the host's engine directory into the container, which skipped the container's own prefetch. --- core/error_handler.func | 83 +++++++++++++++++++---------------------- lxc/install.func | 5 +++ 2 files changed, 43 insertions(+), 45 deletions(-) diff --git a/core/error_handler.func b/core/error_handler.func index 821ba9a..98c8e7d 100644 --- a/core/error_handler.func +++ b/core/error_handler.func @@ -147,15 +147,18 @@ _eh_ok() { # _eh_command_word - the program a command line runs, without # assignments, wrappers or a path: "FOO=1 $STD /usr/bin/npm ci" -> npm _eh_command_word() { - local word - for word in $1; do - [[ "$word" =~ ^[A-Za-z_][A-Za-z0-9_]*= ]] && continue - case "$word" in - sudo | env | command | exec | nohup | time | silent | _cs_shield_hangup | '$STD' | -*) continue ;; - esac - printf '%s' "${word##*/}" - return + local -a words=() + local word found="" + read -ra words <<<"$1" || true + for word in "${words[@]}"; do + if [[ -z "$found" && ! "$word" =~ ^[A-Za-z_][A-Za-z0-9_]*= ]]; then + case "$word" in + sudo | env | command | exec | nohup | time | silent | _cs_shield_hangup | '$STD' | -*) ;; + *) found="${word##*/}" ;; + esac + fi done + printf '%s' "$found" } # ------------------------------------------------------------------------------ @@ -165,46 +168,36 @@ _eh_command_word() { # holds when that tool ran: cargo's 101 is a panic, not an APT error. Otherwise # the sentence names the program that failed. # ------------------------------------------------------------------------------ +# Runs inside the ERR trap: no early returns, every test inside an if. _eh_explanation() { - local exit_code="$1" command="$2" explanation tools word - if declare -f explain_exit_code >/dev/null 2>&1; then - explanation="$(explain_exit_code "$exit_code")" - else - explanation="Exit status ${exit_code}" - fi + local exit_code="$1" command="$2" explanation="" tools word word="$(_eh_command_word "$command")" - case "$command" in - "(("*) - [[ "$exit_code" == 1 ]] && { printf 'Arithmetic expression evaluated to 0'; return; } - ;; - "[["* | "[ "* | "test "*) - [[ "$exit_code" == 1 ]] && { printf 'Test condition was false'; return; } - ;; - esac - if [[ "$command" =~ ^[A-Za-z_][A-Za-z0-9_]*=\$\( ]]; then - printf 'Command substitution exited with status %s' "$exit_code" - return - fi - if [[ "$exit_code" == 1 && "$word" =~ ^(grep|egrep|fgrep|zgrep|rg)$ ]]; then - printf '%s found no match' "$word" - return - fi - if [[ "$exit_code" == 5 ]] && _eh_command_is "$command" "systemctl"; then - printf 'Systemd: unit not found' - return - fi - if [[ "$word" == "return" || "$word" == "exit" ]]; then - printf 'Exit status %s' "$exit_code" - return - fi - - tools="$(_eh_tools_for "${explanation%%:*}")" - if [[ -n "$tools" ]] && ! _eh_command_is "$command" "$tools"; then - explanation="${word:+${word} exited with status ${exit_code}}" - explanation="${explanation:-Exit status ${exit_code}}" - elif [[ "$exit_code" =~ ^[123]$ && -n "$word" ]]; then - explanation="${word} exited with status ${exit_code}" + if [[ "$exit_code" == 1 && "$command" == "(("* ]]; then + explanation="Arithmetic expression evaluated to 0" + elif [[ "$exit_code" == 1 && ("$command" == "[["* || "$command" == "[ "* || "$command" == "test "*) ]]; then + explanation="Test condition was false" + elif [[ "$command" =~ ^[A-Za-z_][A-Za-z0-9_]*=\$\( ]]; then + explanation="Command substitution exited with status ${exit_code}" + elif [[ "$exit_code" == 1 && "$word" =~ ^(grep|egrep|fgrep|zgrep|rg)$ ]]; then + explanation="${word} found no match" + elif [[ "$exit_code" == 5 ]] && _eh_command_is "$command" "systemctl"; then + explanation="Systemd: unit not found" + elif [[ "$word" == "return" || "$word" == "exit" ]]; then + explanation="Exit status ${exit_code}" + else + if declare -f explain_exit_code >/dev/null 2>&1; then + explanation="$(explain_exit_code "$exit_code")" + else + explanation="Exit status ${exit_code}" + fi + tools="$(_eh_tools_for "${explanation%%:*}")" + if [[ -n "$tools" ]] && ! _eh_command_is "$command" "$tools"; then + explanation="${word:+${word} exited with status ${exit_code}}" + explanation="${explanation:-Exit status ${exit_code}}" + elif [[ "$exit_code" =~ ^[123]$ && -n "$word" ]]; then + explanation="${word} exited with status ${exit_code}" + fi fi printf '%s' "$explanation" } diff --git a/lxc/install.func b/lxc/install.func index 6ebbdda..97d832c 100644 --- a/lxc/install.func +++ b/lxc/install.func @@ -377,6 +377,11 @@ _bootstrap() { # (the host is the single telemetry reporter). export TELEMETRY_CONTEXT="container" + # lxc-attach carries the host's engine directory over; it does not exist in here. + if [[ -n "${COMMUNITY_SCRIPTS_CORE_DIR:-}" && ! -d "${COMMUNITY_SCRIPTS_CORE_DIR}" ]]; then + unset COMMUNITY_SCRIPTS_CORE_DIR + fi + # Source core functions _cs_ct_prefetch_engine || true _bootstrap_source core/core.func load_functions From 27109689c08dc39b0097ccece63fc3d2f46d53b7 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:43:42 +0100 Subject: [PATCH 07/11] Report host checks that fail before the install record A run that stopped at the storage, ID or template checks sent nothing, because a terminal status without an install record was dropped. Such a failure now sends the install record first; cancelled dialogs and update runs still send nothing. Exit 64 counts as a configuration problem. --- api/exitcodes.func | 2 +- api/telemetry.func | 15 +++++++++++---- pve/vm-core.func | 1 + tests/telemetry-trace.sh | 22 +++++++++++++++++++--- 4 files changed, 32 insertions(+), 8 deletions(-) diff --git a/api/exitcodes.func b/api/exitcodes.func index 5163f33..16438b4 100644 --- a/api/exitcodes.func +++ b/api/exitcodes.func @@ -247,7 +247,7 @@ categorize_error() { esac case "$code" in 6 | 7 | 22 | 35) echo "network" ;; - 10) echo "config" ;; + 10 | 64) echo "config" ;; 28 | 124 | 211) echo "timeout" ;; 214 | 217 | 219 | 224) echo "storage" ;; 100 | 101 | 102 | 127 | 160 | 161 | 162 | 255) echo "dependency" ;; diff --git a/api/telemetry.func b/api/telemetry.func index 1729e73..f914761 100644 --- a/api/telemetry.func +++ b/api/telemetry.func @@ -214,10 +214,6 @@ post_update_to_api() { [[ "${DIAGNOSTICS:-no}" == "no" ]] && return 0 [[ -z "${RANDOM_UUID:-}" ]] && return 0 - # Unset: no install was ever reported (an update run, or an exit before the - # install began). "false" means the send failed and is still worth a status. - [[ -z "${POST_TO_API_DONE:-}" ]] && return 0 - local exit_code=0 if [[ "$raw_exit_code" =~ ^[0-9]+$ ]]; then exit_code="$raw_exit_code" @@ -246,6 +242,17 @@ post_update_to_api() { ;; esac + # Unset: no install was reported yet. A host run that failed in its checks + # (storage, ID, template) reports one now; an update run inside a container + # or a cancelled dialog does not. "false" means that send failed. + if [[ -z "${POST_TO_API_DONE:-}" ]]; then + if [[ "$pb_status" == "failed" && -n "${NSAPP:-}" ]] && + ! { declare -f _is_container_context >/dev/null 2>&1 && _is_container_context; }; then + post_to_api + fi + [[ -z "${POST_TO_API_DONE:-}" ]] && return 0 + fi + if [[ "$pb_status" == "failed" || "$pb_status" == "unknown" ]]; then _tm_error_context "$exit_code" exit_code="$TM_ERR_CODE" diff --git a/pve/vm-core.func b/pve/vm-core.func index ada9afd..d928c4d 100644 --- a/pve/vm-core.func +++ b/pve/vm-core.func @@ -72,6 +72,7 @@ SPINNER_MSG="" _CORE_FUNC_LOADED=1 BUILD_LOG="${BUILD_LOG:-/tmp/cs-vm-$$.log}" +TELEMETRY_TYPE="vm" export BUILD_LOG COMMUNITY_SCRIPTS_URL="${COMMUNITY_SCRIPTS_URL:-https://raw.githubusercontent.com/community-scripts/ProxmoxVE/main}" diff --git a/tests/telemetry-trace.sh b/tests/telemetry-trace.sh index fcae9bc..ff78b8b 100644 --- a/tests/telemetry-trace.sh +++ b/tests/telemetry-trace.sh @@ -27,9 +27,9 @@ expect() { } json_field() { if command -v jq >/dev/null 2>&1; then - jq -r --arg k "$2" '.[$k] | tostring' "$1" + jq -r --arg k "$2" '.[$k] | tostring' "$1" | tr -d '\r' else - python3 -c 'import json,sys; v=json.load(open(sys.argv[1]))[sys.argv[2]]; print(v if not isinstance(v,bool) else str(v).lower())' "$1" "$2" + python3 -c 'import json,sys; v=json.load(open(sys.argv[1]))[sys.argv[2]]; print(v if not isinstance(v,bool) else str(v).lower())' "$1" "$2" | tr -d '\r' fi } reset() { @@ -39,7 +39,10 @@ reset() { unset TM_ERR_CODE TM_ERR_EXPLANATION POST_TO_API_DONE=true POST_UPDATE_DONE=false } -_tm_send() { printf '%s' "$1" >"$SENT"; } +_tm_send() { + printf '%s' "$1" >"$SENT" + json_field "$SENT" status >>"$TEST_DIR/statuses" +} telemetry_collect_sysinfo() { :; } DIAGNOSTICS=yes RANDOM_UUID=00000000-0000-4000-8000-000000000000 SESSION_ID=test NSAPP=demo BUILD_LOG="$LOG" INSTALL_LOG="$TEST_DIR/none.log" @@ -108,6 +111,19 @@ POST_UPDATE_DONE=true post_update_to_api failed 1 expect "one terminal event per execution" no "$([[ -f "$SENT" ]] && echo yes || echo no)" +# --- a host check failing before the install was reported --- +reset +unset POST_TO_API_DONE +: >"$TEST_DIR/statuses" +CS_ERROR_MSG="Not enough space on 'local'. Required: 500GB, Available: 23.2GB" +post_update_to_api failed 214 +expect "an early host failure is reported with its install record" "installing failed" "$(paste -sd' ' "$TEST_DIR/statuses")" +reset +unset POST_TO_API_DONE +: >"$TEST_DIR/statuses" +post_update_to_api failed 130 +expect "an early abort is not" "" "$(paste -sd' ' "$TEST_DIR/statuses")" + # --- JSON stays valid with awkward text --- reset CS_ERROR_MSG=$'quote " backslash \\ tab \t done' CS_STEP='Step "x"' From 3c5142621ccb968373852520767ea7c101f9dc96 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 13:57:18 +0100 Subject: [PATCH 08/11] Count a Ctrl-C that apt or pip survived as an interrupt The keystroke reaches the program in the foreground, which exits with its own code; bash then never runs the INT trap, and the run was reported as an APT failure. --- core/error_handler.func | 5 +++++ tests/stale-silent-record.sh | 5 +++++ 2 files changed, 10 insertions(+) diff --git a/core/error_handler.func b/core/error_handler.func index 98c8e7d..0e203eb 100644 --- a/core/error_handler.func +++ b/core/error_handler.func @@ -570,6 +570,11 @@ error_handler() { [[ "$exit_code" -eq 0 ]] && return 0 + # apt, pip and the like exit normally after a Ctrl-C reached them; the run was still interrupted. + if [[ -n "$capture" && -s "$capture" ]] && grep -qE 'received signal 2|KeyboardInterrupt' "$capture"; then + exit_code=130 + fi + # set -E hands the ERR trap (which passes no arguments) to $(...) and ( ) too. # The calling shell fails on the same error and reports it. if ((BASH_SUBSHELL > 0 && $# == 0)); then diff --git a/tests/stale-silent-record.sh b/tests/stale-silent-record.sh index d953646..c3f3eab 100644 --- a/tests/stale-silent-record.sh +++ b/tests/stale-silent-record.sh @@ -51,6 +51,11 @@ out="$(error_handler 100 'return 100')" expect "a passed-up failure reports silent's command and line" 1 "$(grep -c 'REPORT 100|apt install -y intel-basekit|5' <<<"$out")" expect "and keeps its capture" 1 "$(ls "$ERRINFO" 2>/dev/null | wc -l)" +# A Ctrl-C that apt survived is still an interrupt. +printf '%s\n' 'EXIT_CODE=100' 'LINE=7' 'COMMAND=apt-get -y dist-upgrade' '--- OUTPUT ---' 'E: Sub-process /usr/bin/apt-listchanges --apt || test $? -lt 10 received signal 2.' >"$ERRINFO" +line=$LINENO; export _SILENT_FAILED_RC=100 _SILENT_FAILED_CMD='apt-get -y dist-upgrade' _SILENT_FAILED_LINE="$line" _SILENT_FAILED_LOG="$LOG"; out="$(error_handler 100 'silent apt-get -y dist-upgrade' 2>/dev/null; true)" +expect "an apt run that received SIGINT is reported as 130" 1 "$(grep -c 'REPORT 130|' <<<"$out")" + # Without a record, "return N" is replaced by the call on that source line. printf '%s\n' 'setup_thing() {' ' fetch_release foo' '}' >"$TEST_DIR/lib.sh" unset _SILENT_FAILED_RC From a5ccee9c5bec248409fe7f1b9a04a19681c1e2ad Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 14:17:49 +0100 Subject: [PATCH 09/11] Keep telemetry from re-entering the error handler json_escape and friends ended with a bare return, which inside an EXIT trap returns the status from before the trap. In a VM script, whose ERR trap is inherited into functions, that fired error_handler during the final report, and every nested call reported again. The senders now run with errexit and the caller's ERR trap off, and the VM cleanup reports a failure even when the install record could not be sent. --- api/API.txt | 4 ++++ api/api.func | 4 ++-- api/errorlog.func | 2 +- api/exitcodes.func | 12 ++++++------ api/telemetry.func | 29 +++++++++++++++++++++++------ pve/vm-core.func | 12 ++++++------ 6 files changed, 42 insertions(+), 21 deletions(-) diff --git a/api/API.txt b/api/API.txt index 8de3c7a..d708af0 100644 --- a/api/API.txt +++ b/api/API.txt @@ -9,7 +9,11 @@ _tm_format_error _tm_one_line _tm_payload _tm_pick_logfile +_tm_post_install +_tm_post_progress _tm_post_run +_tm_post_update +_tm_quiet _tm_send _tm_step_output build_error_string diff --git a/api/api.func b/api/api.func index 824c398..3c30e19 100644 --- a/api/api.func +++ b/api/api.func @@ -41,13 +41,13 @@ _api_source_part() { if declare -f _cs_source_func >/dev/null 2>&1; then _cs_source_func "api/${part}.func" - return + return 0 fi if [[ -n "${COMMUNITY_SCRIPTS_CORE_DIR:-}" && -s "${COMMUNITY_SCRIPTS_CORE_DIR}/api/${part}.func" ]]; then # shellcheck disable=SC1090 source "${COMMUNITY_SCRIPTS_CORE_DIR}/api/${part}.func" - return + return 0 fi local base="${COMMUNITY_SCRIPTS_CORE_URL:-https://raw.githubusercontent.com/community-scripts/core/main}" if command -v curl >/dev/null 2>&1; then diff --git a/api/errorlog.func b/api/errorlog.func index fc3cde6..62e5484 100644 --- a/api/errorlog.func +++ b/api/errorlog.func @@ -34,7 +34,7 @@ json_escape() { if command -v jq &>/dev/null; then printf '%s' "$input" | jq -Rs '.' | sed 's/^"//;s/"$//' - return + return 0 fi printf '%s' "$input" | diff --git a/api/exitcodes.func b/api/exitcodes.func index 16438b4..e90be3a 100644 --- a/api/exitcodes.func +++ b/api/exitcodes.func @@ -227,14 +227,14 @@ explain_exit_code() { categorize_error() { if [[ -n "${ERROR_CATEGORY_OVERRIDE:-}" ]]; then echo "$ERROR_CATEGORY_OVERRIDE" - return + return 0 fi local code="$1" command="${2:-${FAILED_COMMAND:-}}" errinfo tool case "$code" in - 113 | 114 | 122 | 129 | 130 | 143 | 253 | 254) echo "user_aborted"; return ;; - 134 | 137) echo "resource"; return ;; - 139 | 141) echo "signal"; return ;; + 113 | 114 | 122 | 129 | 130 | 143 | 253 | 254) echo "user_aborted"; return 0 ;; + 134 | 137) echo "resource"; return 0 ;; + 139 | 141) echo "signal"; return 0 ;; esac if [[ -z "$command" ]] && declare -f _tm_find_errinfo >/dev/null 2>&1 && errinfo=$(_tm_find_errinfo); then command=$(sed -n 's/^COMMAND=//p' "$errinfo" | head -n1) @@ -242,8 +242,8 @@ categorize_error() { tool="${command%% *}" tool="${tool##*/}" case "$tool" in - systemctl) echo "service"; return ;; - pct | qm | pvesm | pvesh | pveam) echo "proxmox"; return ;; + systemctl) echo "service"; return 0 ;; + pct | qm | pvesm | pvesh | pveam) echo "proxmox"; return 0 ;; esac case "$code" in 6 | 7 | 22 | 35) echo "network" ;; diff --git a/api/telemetry.func b/api/telemetry.func index f914761..d27ab91 100644 --- a/api/telemetry.func +++ b/api/telemetry.func @@ -149,8 +149,25 @@ _tm_send() { # PUBLIC API # ============================================================================== +# _tm_quiet [args] - a sender with errexit and the caller's ERR trap +# off. A failing command in here would otherwise re-enter the error handler, +# which reports again. +_tm_quiet() { + local - err_trap rc=0 + err_trap="$(trap -p ERR)" + set +eE +o pipefail + trap - ERR + "$@" || rc=$? + [[ -n "$err_trap" ]] && eval "$err_trap" + return "$rc" +} + +post_to_api() { _tm_quiet _tm_post_install "$@"; } +post_progress_to_api() { _tm_quiet _tm_post_progress "$@"; } +post_update_to_api() { _tm_quiet _tm_post_update "$@"; } + # post_to_api - the "installing" record; once per execution, retried 3x -post_to_api() { +_tm_post_install() { [[ "${POST_TO_API_DONE:-}" == "true" ]] && return 0 _tm_enabled || return 0 @@ -183,7 +200,7 @@ post_to_api_vm() { } # post_progress_to_api [status] - "validation"/"configuring" ping, full payload, one attempt -post_progress_to_api() { +_tm_post_progress() { _tm_enabled || return 0 local progress_status="${1:-configuring}" @@ -199,7 +216,7 @@ post_progress_to_api() { # the outcome changed, e.g. a retry succeeded). status: done|success, failed, # aborted. exit_code "none" means 0; anything else non-numeric becomes 199. # ------------------------------------------------------------------------------ -post_update_to_api() { +_tm_post_update() { command -v curl &>/dev/null || return 0 local status="${1:-failed}" @@ -315,7 +332,7 @@ _tm_post_run() { # post_tool_to_api [status] [exit_code] - a PVE host tool ran post_tool_to_api() { - _tm_post_run "${TELEMETRY_TOOL_TYPE:-pve}" "$@" + _tm_quiet _tm_post_run "${TELEMETRY_TOOL_TYPE:-pve}" "$@" } # post_addon_to_api [status] [exit_code] - an add-on ran inside a container @@ -325,7 +342,7 @@ post_addon_to_api() { os_type=$(grep "^ID=" /etc/os-release | cut -d= -f2 | tr -d '"' || true) os_version=$(grep "^VERSION_ID=" /etc/os-release | cut -d= -f2 | tr -d '"' || true) fi - var_os="$os_type" var_version="$os_version" _tm_post_run addon "$@" + var_os="$os_type" var_version="$os_version" _tm_quiet _tm_post_run addon "$@" } # telemetry_new_attempt - a retry from the recovery menu becomes its own execution @@ -388,7 +405,7 @@ start_install_timer() { get_install_duration() { if [[ -z "${INSTALL_START_TIME:-}" ]]; then echo "0" - return + return 0 fi local now now=$(date +%s) diff --git a/pve/vm-core.func b/pve/vm-core.func index d928c4d..011af99 100644 --- a/pve/vm-core.func +++ b/pve/vm-core.func @@ -787,12 +787,12 @@ cleanup() { if [[ -n "${TEMP_DIR:-}" && -d "$TEMP_DIR" ]]; then rm -rf "$TEMP_DIR" fi - # Report final telemetry status if post_to_api_vm was called but no update was sent - if [[ "${POST_TO_API_DONE:-}" == "true" && "${POST_UPDATE_DONE:-}" != "true" ]]; then - if declare -f post_update_to_api >/dev/null 2>&1; then - if [[ $exit_code -ne 0 ]]; then - post_update_to_api "failed" "$exit_code" - elif [[ -n "${VMID:-}" ]] && qm config "$VMID" &>/dev/null; then + # The final status nobody sent yet; post_update_to_api decides whether an early failure counts. + if [[ "${POST_UPDATE_DONE:-}" != "true" ]] && declare -f post_update_to_api >/dev/null 2>&1; then + if [[ $exit_code -ne 0 ]]; then + post_update_to_api "failed" "$exit_code" + elif [[ -n "${POST_TO_API_DONE:-}" ]]; then + if [[ -n "${VMID:-}" ]] && qm config "$VMID" &>/dev/null; then # Clean exit with the VM in place: a script that never said so itself. post_update_to_api "done" "none" else From db57b484576d74cb8e4e96b27ec17a0e5f54537e Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 14:25:57 +0100 Subject: [PATCH 10/11] Describe payload v3 and the capture in the api docs --- docs/api.md | 39 ++++++++++++++++++++++++++++++--------- 1 file changed, 30 insertions(+), 9 deletions(-) diff --git a/docs/api.md b/docs/api.md index 3cb5bdd..c1fef0a 100644 --- a/docs/api.md +++ b/docs/api.md @@ -15,20 +15,37 @@ terminal status: it writes `/root/.install-.failed` and an `.errinfo` capture, which the host picks up after `lxc-attach` returns. See [`core/error_handler.func`](../core/error_handler.func). +A host run that fails before its install record went out (storage, ID or +template checks) sends that record first, then the failure. Cancelled dialogs +and update runs inside a container send nothing. + +## What a failure carries (payload version 3) + +| Field | Source | +| ----- | ------ | +| `error_message` | The first `msg_error` of the failing step. Empty when the engine printed none; the server then picks a line from the trace. | +| `error_step` | The last `msg_info` text, or `after ` between steps. | +| `error_phase` | `host` or `container`. | +| `failed_command`, `failed_line`, `failed_function` | The command that failed. A helper's `return N` is replaced by the call on that line, and a `silent()` failure a helper passed up keeps its own command. | +| `error` | `exit_code=N \| [ \| step: …][ \| in …][ \| at line L: …]`, then `---` and the failing command's output, or the failing step's log lines, with package and download progress removed. | + +`core.func` tracks the step (`CS_STEP`, `CS_STEP_DONE`) and the message +(`CS_ERROR_MSG`); the capture format is described at the top of +[`errorlog.func`](../api/errorlog.func). + ## [`exitcodes.func`](../api/exitcodes.func) -`explain_exit_code` — the exit code table — and `categorize_error`. This is the -authoritative copy of the table; `core/error_handler.func` carries a fallback -for the container case where this file is not loaded. The table borrows curl's -and APT's numbering, so the telemetry summary (`_tm_explain` in -`errorlog.func`) runs it through the handler's tool guard when the failing -command is known, and `categorize_error` files `systemctl` and `pct`/`qm` -failures under their own categories rather than the code's. +`explain_exit_code` — the exit code table — and `categorize_error`. The one copy +of the table: the container loads this file too. The table borrows curl's and +APT's numbering, so the explanation (`_eh_explanation` in the error handler) +names the program that failed when it is not that tool, and `categorize_error` +files `systemctl` and `pct`/`qm` failures under their own categories. ## [`errorlog.func`](../api/errorlog.func) -Extracting the useful part of a failed run's log: `get_error_log`, -`get_error_text`, `get_full_log`, `write_errinfo`, `build_error_string`. +The capture and the trace: `_tm_clean_log` (the noise filter, `_TM_NOISE`), +`_tm_step_output`, `_tm_error_context`, `build_error_string`. Loaded by the +container as well, for `silent()` and the error handler. Which log to read is picked by `_tm_pick_logfile`: the combined install log, then `INSTALL_LOG`, `BUILD_LOG`, `SILENT_LOGFILE`. The log a run writes to is @@ -53,4 +70,8 @@ Assembly and delivery. The public entry points: | `post_tool_to_api` | A host tool ran | | `post_addon_to_api` | An add-on ran | +They run with errexit and the caller's ERR trap off (`_tm_quiet`), so a failing +command in here never reaches the error handler. + Telemetry is opt-out through `/usr/local/community-scripts/diagnostics`. +`TELEMETRY_URL` overrides the endpoint on the host and in the container. From e85e8af7dabff90c274e6a62ac110bd43d8730de Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Tue, 27 Oct 2026 14:53:18 +0100 Subject: [PATCH 11/11] Regenerate ui/API.txt for the telemetry functions --- ui/API.txt | 17 ++++++++++++++--- 1 file changed, 14 insertions(+), 3 deletions(-) diff --git a/ui/API.txt b/ui/API.txt index 82899f4..7e91610 100644 --- a/ui/API.txt +++ b/ui/API.txt @@ -4,6 +4,7 @@ _container_write_failure _cs_ask_update_mode _cs_clear _cs_conffile_list +_cs_drop_silent_record _cs_engine_ref_line _cs_host_arch _cs_host_version_line @@ -22,6 +23,7 @@ _dev_step_key _dev_step_start _dev_timing_dir _eh_command_is +_eh_command_word _eh_destroy_container _eh_explanation _eh_hint_from_log @@ -36,9 +38,11 @@ _eh_quiet_spinner _eh_report _eh_resolve_log _eh_signal_exit +_eh_source_line _eh_tools_for _eh_warn _eh_write_debug_log +_eh_write_errinfo _get_current_ip _in_zone_tab _is_container_context @@ -56,11 +60,21 @@ _stop_container_if_installing _telemetry_report_exit _tm_clean_log _tm_enabled +_tm_error_context _tm_explain _tm_find_errinfo +_tm_focus +_tm_format_error +_tm_one_line _tm_payload _tm_pick_logfile +_tm_post_install +_tm_post_progress +_tm_post_run +_tm_post_update +_tm_quiet _tm_send +_tm_step_output _vars_file_value _write_storage_to_vars advanced_settings @@ -119,8 +133,6 @@ get_active_logfile get_app_defaults_path get_current_ip get_error_log -get_error_text -get_full_log get_header get_install_duration get_lxc_ip @@ -220,5 +232,4 @@ validate_tags validate_timezone validate_vlan_tag variables -write_errinfo write_update_entrypoint