Report failures and warnings to the server, tagged with which they are

Buildroot/board/FOG/FOS/rootfs_overlay/usr/share/fog/lib/funcs.sh

@@ -1614,6 +1614,45 @@ correctVistaMBR() {
     checkStatus $? "done" "Could not apply fixed MBR (${FUNCNAME[0]})\n   Args Passed: $*"
     debugPause
 }
+# Tells the FOG server that something went wrong, and carries on regardless
+#
+# Until fogproject#1206 neither handleError nor handleWarning reported anything
+# at all -- they printed a banner and, for an error, exited -- so a real
+# imaging failure (bad image, mount failure, partition error) was invisible to
+# FOG. The task simply stopped progressing, HOST_IMAGE_FAIL could not fire, and
+# the notification plugins registered for it had never run on any server. The
+# only failure FOG ever heard about was a storage node problem, through
+# fog.checkmount -> blame.php, and that re-queues rather than fails.
+#
+# The server records both types against the task in `taskLog` and in its own
+# log; only an error fires the failure event, because a warning means this
+# machine carried on.
+#
+# Best effort, and deliberately so. This must not change anything the person
+# standing in front of the machine sees or waits for: it is time bounded, its
+# output is discarded, and its exit status is ignored. A server that predates
+# the endpoint answers 404 and nothing happens here.
+#
+# $1 is the report type, error or warning
+# $2 is the message, as it was passed to the handler
+reportToServer() {
+    local type="$1"
+    local str="$2"
+    local report=""
+    [[ -z $web ]] && return 0
+    # printf %b first so the "\n" the callers embed in their message becomes a
+    # real newline; the server flattens control characters back to spaces, and
+    # would otherwise be handed the two literal characters.
+    report=$(printf '%b' "$str" 2>/dev/null) || report="$str"
+    curl -Lks --max-time 5 \
+        --data-urlencode "mac=$mac" \
+        --data-urlencode "sysuuid=$sysuuid" \
+        --data-urlencode "type=$type" \
+        --data-urlencode "text=$report" \
+        --data-urlencode "script=${0##*/}" \
+        "${web}service/taskerror.php" &>/dev/null || :
+    return 0
+}
 # Prints an error with visible information
 #
 # $1 is the string to inform what went wrong
@@ -1628,6 +1667,7 @@ handleError() {
     echo "##############################################################################"
     echo "Init Version: $initversion"
     echo -e "$str\n"
+    reportToServer error "$str"
     echo "Kernel variables and settings:"
     cat /proc/cmdline | sed 's/ad.*=.* //g'
     #
@@ -1671,6 +1711,7 @@ handleWarning() {
     echo "#                                                                            #"
     echo "##############################################################################"
     echo -e "$str"
+    reportToServer warning "$str"
     echo "##############################################################################"
     echo "#                                                                            #"
     echo "#                          Will continue in 1 minute                         #"

tests/README.md

@@ -55,6 +55,15 @@ tests/checks/mbr-extended.sh  # MBR tables carrying an extended partition with
                               # container rather than partclone'ing it. Where a
                               # real sfdisk is present each computed table is
                               # also applied to a sparse file
+tests/checks/error-report.sh  # the failure report handleError() sends to
+                              # service/taskerror.php (fogproject#1206): it goes
+                              # to the right URL with mac, sysuuid and the
+                              # message, it is time bounded and url-encoded, the
+                              # "\n" the callers embed is expanded before
+                              # sending, nothing it does reaches the operator's
+                              # console, a failed report still lets handleError
+                              # reach its reboot notice, and no $web means no
+                              # attempt at all
 tests/checks/wipe.sh          # wipeDisk() issues the right erase primitive per
                               # device class (NVMe/SSD/HDD) and mode
                               # (fast/normal/full), never issues an `nvme format`

tests/checks/error-report.sh

@@ -0,0 +1,215 @@
+#!/bin/bash
+#
+# Assertion harness for the reports handleError() and handleWarning() send.
+#
+#   tests/checks/error-report.sh   # run all cases, exit non-zero on any failure
+#
+# handleError() used to print its banner and exit, reporting nothing to the
+# server, so a real imaging failure was invisible to FOG: HOST_IMAGE_FAIL could
+# not fire and the notification plugins registered for it had never run
+# (fogproject#1206). Both handlers now POST to service/taskerror.php through
+# reportToServer(), tagged error or warning: the server records either against
+# the task, and only an error is a failure.
+#
+# What matters here is not that the report arrives -- that is the server's
+# harness -- but that trying to send it cannot change what the person standing
+# at the machine sees. So the assertions are about the shape of the call and
+# about handleError still finishing when the call does not: time bounded, output
+# discarded, exit status ignored, skipped when there is no server to talk to.
+#
+# Mechanism mirrors tests/checks/sector-size.sh: source a sandbox copy of the
+# library with its hardcoded /usr/share/fog/lib path rewritten, and PATH-shadow
+# the external tools with deterministic stubs. curl is the stub that matters --
+# it records its argv rather than making a request.
+#
+# One thing here is asserted as behaviour rather than as implementation: no FOS
+# script sets errexit today, so the `|| :` on the curl is defensive and cannot
+# be isolated by a case. Case 5 pins what actually matters instead -- that
+# handleError still reaches its reboot notice when the report fails -- which
+# stays true however that is achieved.
+
+HERE="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
+REPO_LIB="$HERE/../../Buildroot/board/FOG/FOS/rootfs_overlay/usr/share/fog/lib"
+
+[[ -f $REPO_LIB/funcs.sh ]] || { echo "ERROR: cannot find funcs.sh under $REPO_LIB" >&2; exit 2; }
+
+SANDBOX="$(mktemp -d)"
+trap 'rm -rf "$SANDBOX"' EXIT
+
+cp "$REPO_LIB/partition-funcs.sh" "$SANDBOX/partition-funcs.sh"
+sed -e "s#^\. /usr/share/fog/lib/partition-funcs\.sh#. $SANDBOX/partition-funcs.sh#" \
+    "$REPO_LIB/funcs.sh" > "$SANDBOX/funcs.sh"
+
+STUBBIN="$SANDBOX/bin"
+mkdir -p "$STUBBIN"
+
+# curl double: records one line per argument into $SANDBOX/curl.argv, then exits
+# with $FAKE_CURL_RC. Recording argv rather than a flattened string is what lets
+# a case tell "--data-urlencode error=a b" from two separate arguments.
+cat > "$STUBBIN/curl" <<'EOF'
+#!/bin/bash
+: > "$SANDBOX/curl.called"
+printf '%s\n' "$@" > "$SANDBOX/curl.argv"
+echo "curl stdout must not reach the console"
+echo "curl stderr must not reach the console" >&2
+exit "${FAKE_CURL_RC:-0}"
+EOF
+chmod +x "$STUBBIN/curl"
+
+# The reboot countdown, so a case runs instantly rather than in a minute.
+printf '#!/bin/bash\nexit 0\n' > "$STUBBIN/usleep"
+chmod +x "$STUBBIN/usleep"
+
+PASS=0
+FAIL=0
+
+# arg_present <exact argument> -- true if curl received it as one whole argument.
+arg_present() { grep -Fxq -- "$1" "$SANDBOX/curl.argv" 2>/dev/null; }
+
+note() {
+    if [[ -z $2 ]]; then
+        echo "PASS: $1"
+        PASS=$((PASS + 1))
+    else
+        echo "FAIL: $1 ($2)"
+        FAIL=$((FAIL + 1))
+        [[ -f $SANDBOX/curl.argv ]] && echo "      argv: $(tr '\n' '|' < "$SANDBOX/curl.argv")"
+    fi
+}
+
+# run_handle_error <message> -- drives handleError in a subshell with the
+# environment a case has set, and captures everything it wrote to the console.
+# handleError ends in `exit 1`, which is why this has to be a subshell.
+run_handle_error() {
+    rm -f "$SANDBOX/curl.called" "$SANDBOX/curl.argv"
+    OUT="$(
+        set +u
+        export PATH="$STUBBIN:$PATH"
+        export SANDBOX="$SANDBOX"
+        export FAKE_CURL_RC
+        . "$SANDBOX/funcs.sh" >/dev/null 2>&1
+        web="$CASE_WEB"
+        mac="$CASE_MAC"
+        sysuuid="$CASE_UUID"
+        isdebug=""
+        handleError "$1"
+    )" 2>&1
+}
+
+# run_handle_warning -- the same, but handleWarning returns rather than exiting,
+# so the subshell is only for symmetry. usleep is stubbed, so its minute is free.
+run_handle_warning() {
+    rm -f "$SANDBOX/curl.called" "$SANDBOX/curl.argv"
+    OUT="$(
+        set +u
+        export PATH="$STUBBIN:$PATH"
+        export SANDBOX="$SANDBOX"
+        export FAKE_CURL_RC
+        . "$SANDBOX/funcs.sh" >/dev/null 2>&1
+        web="$CASE_WEB"
+        mac="$CASE_MAC"
+        sysuuid="$CASE_UUID"
+        isdebug=""
+        handleWarning "$1"
+    )" 2>&1
+}
+
+CASE_WEB="http://fog.example/fog/"
+CASE_MAC="02:00:00:00:0E:11"
+CASE_UUID="4c4c4544-0044-0000-8000-000000000000"
+
+# 1. The report is sent, to the right place, with the right fields.
+FAKE_CURL_RC=0
+run_handle_error "Could not mount images folder (fog.mount)"
+why=""
+[[ -f $SANDBOX/curl.called ]] || why="curl was not called at all"
+arg_present "http://fog.example/fog/service/taskerror.php" || why="${why:+$why; }wrong or missing endpoint URL"
+arg_present "mac=02:00:00:00:0E:11" || why="${why:+$why; }mac not sent"
+arg_present "sysuuid=4c4c4544-0044-0000-8000-000000000000" || why="${why:+$why; }sysuuid not sent"
+arg_present "text=Could not mount images folder (fog.mount)" || why="${why:+$why; }report text not sent as one argument"
+arg_present "type=error" || why="${why:+$why; }not tagged as an error, so the server cannot tell it from a warning"
+note "reports to service/taskerror.php with mac, sysuuid, type and the message" "$why"
+
+# 2. Bounded, and encoded rather than concatenated into the body.
+why=""
+arg_present "--max-time" || why="no --max-time, so an unreachable server adds to the wait before the reboot"
+grep -Fxq -- "--data-urlencode" "$SANDBOX/curl.argv" || why="${why:+$why; }fields are not url-encoded, so a message containing & splits into extra fields"
+note "the call is time bounded and its fields are encoded" "$why"
+
+# 3. The escapes the callers embed become real newlines before sending. Every
+#    caller writes "...(\$0)\n   Args Passed: \$*", and sending the two literal
+#    characters would put a visible backslash-n in an admin's notification.
+FAKE_CURL_RC=0
+run_handle_error 'Could not mount images folder ($0)\n   Args Passed: --target /images'
+sent="$(grep -F -- 'text=' "$SANDBOX/curl.argv" | head -1)"
+why=""
+[[ $sent == *'\n'* ]] && why="the literal two characters \\n were sent instead of a newline"
+[[ $(grep -c . <<< "$(printf '%s' "$sent")") -lt 1 ]] && why="${why:+$why; }nothing was sent"
+note "message escapes are expanded before sending" "$why"
+
+# 4. Nothing the report does may reach the console. The operator's screen is the
+#    whole reason handleError exists.
+FAKE_CURL_RC=0
+run_handle_error "Could not mount images folder (fog.mount)"
+why=""
+[[ $OUT == *"curl stdout must not reach the console"* ]] && why="curl stdout is printed to the operator"
+[[ $OUT == *"curl stderr must not reach the console"* ]] && why="${why:+$why; }curl stderr is printed to the operator"
+[[ $OUT != *"An error has been detected"* ]] && why="${why:+$why; }the error banner itself stopped being printed"
+[[ $OUT != *"Could not mount images folder"* ]] && why="${why:+$why; }the message itself stopped being printed"
+note "the report is silent and the banner is unaffected" "$why"
+
+# 5. A failing curl must not change anything. errexit anywhere up the call chain
+#    plus a bare curl would abort handleError before it printed the reboot
+#    notice -- the machine would just sit there.
+FAKE_CURL_RC=7
+run_handle_error "Could not mount images folder (fog.mount)"
+why=""
+[[ $OUT != *"An error has been detected"* ]] && why="the banner was not printed"
+[[ $OUT != *"Computer will reboot"* ]] && why="${why:+$why; }handleError did not reach the reboot notice after curl failed"
+note "a failed report does not stop handleError finishing" "$why"
+
+# 6. No server configured -- registration paths and debug shells run without
+#    \$web -- must not try at all. curl would resolve "service/taskerror.php" as
+#    a relative URL and fail slowly.
+CASE_WEB=""
+FAKE_CURL_RC=0
+run_handle_error "Could not mount images folder (fog.mount)"
+why=""
+[[ -f $SANDBOX/curl.called ]] && why="curl was called with no \$web set"
+[[ $OUT != *"An error has been detected"* ]] && why="${why:+$why; }the banner was not printed"
+note "no \$web means no attempt" "$why"
+
+# 7. A warning reports too, tagged as one. The server keys the notification off
+#    this: an error fires HOST_IMAGE_FAIL, a warning only records, because the
+#    machine carried on. Sending a warning untagged would announce a failed
+#    deploy for a task that went on to succeed.
+CASE_WEB="http://fog.example/fog/"
+FAKE_CURL_RC=0
+run_handle_warning "Could not determine the disk size (getDiskSize)"
+why=""
+[[ -f $SANDBOX/curl.called ]] || why="curl was not called at all"
+arg_present "type=warning" || why="${why:+$why; }not tagged as a warning, so the server would treat it as a failure"
+arg_present "text=Could not determine the disk size (getDiskSize)" || why="${why:+$why; }report text not sent as one argument"
+arg_present "http://fog.example/fog/service/taskerror.php" || why="${why:+$why; }wrong or missing endpoint URL"
+note "handleWarning reports, tagged warning" "$why"
+
+# 8. And it changes nothing about what the operator sees or how long they wait.
+why=""
+[[ $OUT != *"A warning has been detected"* ]] && why="the warning banner was not printed"
+[[ $OUT != *"Could not determine the disk size"* ]] && why="${why:+$why; }the message itself stopped being printed"
+[[ $OUT != *"Will continue in 1 minute"* ]] && why="${why:+$why; }handleWarning did not reach its continue notice"
+[[ $OUT == *"curl stdout must not reach the console"* ]] && why="${why:+$why; }curl stdout is printed to the operator"
+note "the warning banner and wait are unaffected" "$why"
+
+# 9. A failing curl must not stop a warning from being one -- the machine is
+#    still going to carry on imaging.
+FAKE_CURL_RC=7
+run_handle_warning "Could not determine the disk size (getDiskSize)"
+why=""
+[[ $OUT != *"Will continue in 1 minute"* ]] && why="handleWarning did not finish after curl failed"
+note "a failed warning report does not stop handleWarning finishing" "$why"
+
+echo
+echo "$PASS passed, $FAIL failed"
+[[ $FAIL -eq 0 ]] || exit 1
+exit 0