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..d708af0 100644 --- a/api/API.txt +++ b/api/API.txt @@ -1,11 +1,21 @@ _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 build_error_string categorize_error detect_arm @@ -15,8 +25,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 +37,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..3c30e19 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) @@ -93,10 +41,14 @@ _api_source_part() { if declare -f _cs_source_func >/dev/null 2>&1; then _cs_source_func "api/${part}.func" - return + return 0 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 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 # shellcheck disable=SC1090 diff --git a/api/errorlog.func b/api/errorlog.func index c894d3b..62e5484 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" | @@ -32,10 +34,9 @@ json_escape() { if command -v jq &>/dev/null; then printf '%s' "$input" | jq -Rs '.' | sed 's/^"//;s/"$//' - return + return 0 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/exitcodes.func b/api/exitcodes.func index ad83c87..e90be3a 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,44 +222,32 @@ 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" - 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 - # 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 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" ;; - 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" ;; @@ -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 -# ------------------------------------------------------------------------------ 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..d27ab91 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,34 @@ _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) -# ------------------------------------------------------------------------------ +# _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() -# -# - 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() { +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 +_tm_post_install() { [[ "${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,52 +186,21 @@ 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() { +# post_progress_to_api [status] - "validation"/"configuring" ping, full payload, one attempt +_tm_post_progress() { _tm_enabled || return 0 local progress_status="${1:-configuring}" @@ -285,39 +210,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 +# 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() -# -# - 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() { +_tm_post_update() { 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 +231,10 @@ 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. - [[ -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 +248,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" ;; @@ -375,11 +259,25 @@ 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 - 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 +289,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). -# ------------------------------------------------------------------------------ - -# ------------------------------------------------------------------------------ -# post_tool_to_api() - PVE host tool usage report +# Each run is its own execution with a fresh id. Failures carry the same error +# fields as installs. # ------------------------------------------------------------------------------ -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_quiet _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..0e203eb 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] +# +# 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] # -# - 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 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,60 @@ _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 -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" +} + # ------------------------------------------------------------------------------ -# _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. +# Runs inside the ERR trap: no early returns, every test inside an if. _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}" - fi - if [[ "$exit_code" == 5 ]] && _eh_command_is "$command" "systemctl"; then + local exit_code="$1" command="$2" explanation="" tools word + word="$(_eh_command_word "$command")" + + 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" } @@ -371,16 +224,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 +284,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 +516,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 @@ -687,17 +570,28 @@ 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, 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 +600,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 +612,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/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. 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/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..97d832c 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})" } @@ -372,9 +377,16 @@ _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 + _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 +431,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 +1425,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 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 diff --git a/pve/vm-core.func b/pve/vm-core.func index f7e479f..011af99 100644 --- a/pve/vm-core.func +++ b/pve/vm-core.func @@ -71,6 +71,10 @@ SPINNER_MSG="" [[ -n "${_CORE_FUNC_LOADED:-}" ]] && return _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}" load_api_functions() { @@ -302,12 +306,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 +333,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 +343,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 +379,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 +640,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 +656,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 +710,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" @@ -752,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 @@ -2311,10 +2346,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" 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..c3f3eab 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,25 @@ 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)" + +# 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 +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..ff78b8b --- /dev/null +++ b/tests/telemetry-trace.sh @@ -0,0 +1,143 @@ +#!/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" | 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" | tr -d '\r' + 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" + 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" + +# --- 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)" + +# --- 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"' +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)) 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