Show what the failing command printed, and keep verbose output in the log

.github/workflows/verify-split-files.yml

@@ -32,6 +32,7 @@ on:
       - "tests/forge-version-key.sh"
       - "tests/nodejs-key-refresh.sh"
       - "tests/forge-connection.sh"
+      - "tests/failed-command-output.sh"
       - "tests/forge-release-json.sh"
       - ".github/workflows/verify-split-files.yml"
   push:
@@ -56,6 +57,7 @@ on:
       - "tests/forge-version-key.sh"
       - "tests/nodejs-key-refresh.sh"
       - "tests/forge-connection.sh"
+      - "tests/failed-command-output.sh"
       - "tests/forge-release-json.sh"
       - ".github/workflows/verify-split-files.yml"
   workflow_dispatch:
@@ -108,6 +110,9 @@ jobs:
       - name: Forge connection diagnosis tests
         run: bash tests/forge-connection.sh
 
+      - name: Failed command output tests
+        run: bash tests/failed-command-output.sh
+
       - name: Forge release lookup tests
         run: bash tests/forge-release-json.sh
 

core/core.func

@@ -369,11 +369,8 @@ default_vars() {
 # - If DEV_MODE_TRACE=true: Enables bash tracing (set -x)
 # ------------------------------------------------------------------------------
 set_std_mode() {
-  if [ "${VERBOSE:-no}" = "yes" ]; then
-    STD=""
-  else
-    STD="silent"
-  fi
+  # Verbose shows the output live and still keeps it in the log; silent() reads VERBOSE.
+  STD="silent"
 
   # Enable bash tracing if trace mode active
   if [[ "${DEV_MODE_TRACE:-false}" == "true" ]]; then
@@ -950,8 +947,16 @@ silent() {
   [[ -f "$logfile" ]] && start_bytes=$(stat -c%s "$logfile" 2>/dev/null || echo 0)
   [[ ! "$start_bytes" =~ ^[0-9]+$ ]] && start_bytes=0
 
-  "$@" >>"$logfile" 2>&1
-  local rc=$?
+  local rc
+  if [[ "${VERBOSE:-no}" == "yes" ]]; then
+    # Not a pipe: the command must stay in this shell so functions keep their side effects.
+    "$@" > >(tee -a "$logfile") 2>&1
+    rc=$?
+    wait $! 2>/dev/null
+  else
+    "$@" >>"$logfile" 2>&1
+    rc=$?
+  fi
 
   # Restore error handling ONLY if it was active before this call.
   if $_restore_errexit; then

core/error_handler.func

@@ -410,6 +410,21 @@ _eh_print_log_tail() {
   echo -e "${TAB}-----------------------------------\n" >&2
 }
 
+# ------------------------------------------------------------------------------
+# _eh_print_failed_output() - what the failing command printed, from .errinfo
+#
+# The exit code alone says nothing; this is the part of the log that does.
+# ------------------------------------------------------------------------------
+_eh_print_failed_output() {
+  local errinfo="$1" lines="${2:-25}" out
+  [[ -n "$errinfo" && -s "$errinfo" ]] || return 0
+  out="$(awk 'found { print } /^--- OUTPUT ---$/ { found = 1 }' "$errinfo" | cut -c1-400 | tail -n "$lines")"
+  [[ -n "$out" ]] || return 0
+  echo -e "\n${TAB}--- Output of the failing command ---" >&2
+  printf '%s\n' "$out" >&2
+  echo -e "${TAB}--------------------------------------\n" >&2
+}
+
 # ------------------------------------------------------------------------------
 # _eh_hint_missing_command() - name what could not be run, and where it comes from
 #

incus/backend.func

@@ -1245,6 +1245,7 @@ incus_run_install_script_with_recovery() {
   fi
 
   [[ -n "$error_explanation" ]] && echo -e "${TAB}${RD}Error: ${error_explanation}${CL}" && echo ""
+  declare -f _eh_print_failed_output >/dev/null 2>&1 && _eh_print_failed_output "${TELEMETRY_ERRINFO:-}"
   if [[ $install_exit_code -eq 10 ]]; then
     echo -e "${TAB}${INFO} Privileged / nesting / device hint:"
     echo -e "${TAB}${INFO}  • Privileged: ${GN}security.privileged=true${CL} (USB, Docker-in-LXC)"

pve/backend.func

@@ -1597,6 +1597,7 @@ PROFILE
       echo -e "${TAB}${RD}Error: ${error_explanation}${CL}"
       echo ""
     fi
+    declare -f _eh_print_failed_output >/dev/null 2>&1 && _eh_print_failed_output "${TELEMETRY_ERRINFO:-}"
 
     if [[ $install_exit_code -eq 10 ]]; then
       echo -e "${TAB}${INFO} This error usually means the container needs ${GN}privileged${CL} mode or Docker/nesting support."

tests/failed-command-output.sh

@@ -0,0 +1,90 @@
+#!/usr/bin/env bash
+set -uo pipefail
+
+CORE_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")/.." && pwd)"
+eval "$(awk '/^(silent|set_std_mode)[(][)] [{]/,/^}/' "$CORE_DIR/core/core.func")"
+eval "$(awk '/^_eh_print_failed_output[(][)] [{]/,/^}/' "$CORE_DIR/core/error_handler.func")"
+
+TEST_DIR="$(mktemp -d)"
+trap 'rm -rf -- "$TEST_DIR"' EXIT
+LOGFILE="$TEST_DIR/install.log"
+export TAB="  "
+passed=0 failed=0
+
+get_active_logfile() { echo "$LOGFILE"; }
+debug_log() { :; }
+# A failing command that talks on both streams, and a function with a side effect.
+noisy() {
+  echo "stdout line"
+  echo "stderr line" >&2
+  return 3
+}
+marker() {
+  MARK="set"
+  echo "marker ran"
+}
+
+expect() {
+  if [[ "$2" == "$3" ]]; then
+    echo "PASS $1"
+    passed=$((passed + 1))
+  else
+    echo "FAIL $1: expected <$2>, got <$3>" >&2
+    failed=$((failed + 1))
+  fi
+}
+reset() {
+  : >"$LOGFILE"
+  rm -f "$LOGFILE.errinfo"
+  unset _SILENT_FAILED_RC _SILENT_FAILED_CMD _SILENT_FAILED_LINE _SILENT_FAILED_LOG MARK
+}
+
+# --- silent, quiet mode ---
+reset
+export VERBOSE=no
+set_std_mode
+expect "quiet mode runs through silent" silent "$STD"
+$STD noisy >"$TEST_DIR/shown" 2>&1
+rc=$?
+expect "quiet: exit code is kept" 3 "$rc"
+expect "quiet: nothing reaches the terminal" "" "$(cat "$TEST_DIR/shown")"
+expect "quiet: silent reports the failure" 3 "${_SILENT_FAILED_RC:-unset}"
+expect "quiet: both streams are in the log" 2 "$(grep -c 'line' "$LOGFILE")"
+expect "quiet: errinfo records the exit code" 1 "$(grep -c '^EXIT_CODE=3$' "$LOGFILE.errinfo")"
+expect "quiet: errinfo carries the output" 1 "$(grep -c '^stderr line$' "$LOGFILE.errinfo")"
+
+# --- silent, verbose mode ---
+reset
+export VERBOSE=yes
+set_std_mode
+expect "verbose mode also runs through silent" silent "$STD"
+$STD noisy >"$TEST_DIR/shown" 2>&1
+rc=$?
+expect "verbose: exit code is kept" 3 "$rc"
+expect "verbose: the output is shown live" 2 "$(grep -c 'line' "$TEST_DIR/shown")"
+expect "verbose: the output is still logged" 2 "$(grep -c 'line' "$LOGFILE")"
+expect "verbose: errinfo is written" 1 "$(grep -c '^stderr line$' "$LOGFILE.errinfo")"
+expect "verbose: silent reports the failure" 3 "${_SILENT_FAILED_RC:-unset}"
+
+reset
+$STD marker >/dev/null
+expect "verbose: a function keeps its side effects" set "${MARK:-unset}"
+expect "verbose: success leaves no errinfo" no "$([[ -f "$LOGFILE.errinfo" ]] && echo yes || echo no)"
+
+# --- the host-side display of the failing command's output ---
+ERRINFO="$TEST_DIR/errinfo"
+long="$(printf 'x%.0s' $(seq 1 600))"
+printf 'EXIT_CODE=1\nLINE=34\nCOMMAND=pnpm install --frozen-lockfile\n--- OUTPUT ---\nScope: all 36 workspace projects\n ERR_PNPM_OUTDATED_LOCKFILE  Cannot install with "frozen-lockfile"\n%s\n' "$long" >"$ERRINFO"
+shown="$(_eh_print_failed_output "$ERRINFO" 2>&1)"
+expect "the failing output gets a heading" 1 "$(printf '%s\n' "$shown" | grep -c 'Output of the failing command')"
+expect "the pnpm error is shown" 1 "$(printf '%s\n' "$shown" | grep -c 'ERR_PNPM_OUTDATED_LOCKFILE')"
+expect "the header lines of errinfo are not shown" 0 "$(printf '%s\n' "$shown" | grep -c '^EXIT_CODE=')"
+expect "overlong lines are cut" 400 "$(printf '%s\n' "$shown" | grep 'xxxx' | head -n1 | awk '{print length($0)}')"
+
+printf 'EXIT_CODE=1\nLINE=34\nCOMMAND=true\n--- OUTPUT ---\n' >"$ERRINFO"
+expect "an empty output section prints nothing" "" "$(_eh_print_failed_output "$ERRINFO" 2>&1)"
+expect "a missing errinfo prints nothing" "" "$(_eh_print_failed_output "$TEST_DIR/nope" 2>&1)"
+expect "no errinfo path prints nothing" "" "$(_eh_print_failed_output "" 2>&1)"
+
+printf '%s passed, %s failed\n' "$passed" "$failed"
+((failed == 0))

ui/API.txt

@@ -25,6 +25,7 @@ _eh_hint_node_oom
 _eh_info
 _eh_offer_container_removal
 _eh_ok
+_eh_print_failed_output
 _eh_print_log_tail
 _eh_quiet_spinner
 _eh_report