fix(updates): не выдавать успешное обновление за ошибку "Failed to execute"

Воркер компонентного действия перенаправлял stderr в тот же файл, что и stdout (2>&1). Действие печатает результат в stdout одним JSON-объектом, а stderr — предупреждения apk/opkg, вывод init-скрипта при рестарте — попадал в тот же файл после JSON. Разбор всего файла падал, построчный фолбэк не находил объекта, и finish_component_job писал синтетический success: false с последней строкой лога в качестве сообщения. Особенно надёжно это ломало самообновление Tachyon: install_tachyon рестартует сервис, будучи предком воркера, поэтому вывод рестарта гарантированно ложился поверх канала результата. Теперь stderr пишется в отдельный <job>.out.stderr, он же используется как источник сообщения, когда воркер действительно умер, не напечатав результат. Файл убирается вместе с заданием и подметается orphan-очисткой. Заодно валидация sing-box перестала судить о бинарнике по коду возврата: popen().close() отдаёт сырой wait-статус, а command_output отбрасывал stdout при любом ненулевом статусе. `sing-box version` печатает версию и может завершиться ненулевым кодом или получить сигнал от остановки сервиса перед установкой — валидация получала "", объявляла рабочий пакет битым и откатывала установку с exit_code 129 (128+SIGHUP). Добавлен command_output_lenient, он же чинит показ версии в дашборде.
2026-08-10 05:21:19 +03:00
parent dce098ff7c
commit 6cf90e3e84
4 changed files with 193 additions and 5 deletions
@@ -86,6 +86,19 @@ function command_output(command) {
    return as_string(data);
 }

+// Like command_output but keeps stdout regardless of the exit status. popen()'s
+// close() yields a raw wait status, so a command that writes a perfectly good
+// answer and then exits non-zero - or is signalled - loses all of it above.
+function command_output_lenient(command) {
+    let pipe = fs.popen(command, "r");
+    if (!pipe)
+        return "";
+
+    let data = pipe.read("all");
+    pipe.close();
+    return data != null ? as_string(data) : "";
+}
+
 function command_output_from_args(args) {
    return command_output(command_from_args(args));
 }
@@ -1328,11 +1341,16 @@ function read_sing_box_binary_version(binary, library_dir) {
    if (binary == "" || !file_exists(binary))
        return "";

+    // stderr is dropped but stdout is kept whatever the exit status: sing-box
+    // prints "sing-box version X" and can still exit non-zero (or be signalled by
+    // the service stop that precedes the install). Judging the binary by its exit
+    // code made every install report "failed validation" and roll a working
+    // sing-box back - the version string itself is the only reliable signal.
    let command = command_from_args([ binary, "version" ]);
    if (as_string(library_dir || "") != "")
        command = command_env({ LD_LIBRARY_PATH: as_string(library_dir) }) + " " + command;

-    return trim(helper_output_input(command_output(command), "stdin-first-line-last-field", []));
+    return trim(helper_output_input(command_output_lenient("(" + command + ") 2>/dev/null"), "stdin-first-line-last-field", []));
 }

 function validate_sing_box_extended_binary(binary, library_dir) {
@@ -1641,6 +1641,7 @@ function component_cleanup_jobs() {
        let state_file = component_job_state_path_value(path_basename_without_suffix(output_path, ".out"));
        if (state_file == "" || fs.stat(state_file) == null || !component_job_running_is(state_file, true)) {
            remove_file(output_path);
+            remove_file(output_path + ".stderr");
            remove_file(output_path + ".json");
        }
    }
@@ -1653,6 +1654,14 @@ function component_cleanup_jobs() {
        "-mmin", "+" + as_string(COMPONENT_JOB_ORPHAN_OUTPUT_TTL_MINUTES),
        "-delete"
    ]);
+    command_success_from_args([
+        "find",
+        COMPONENT_JOB_DIR,
+        "-type", "f",
+        "-name", "*.out.stderr",
+        "-mmin", "+" + as_string(COMPONENT_JOB_ORPHAN_OUTPUT_TTL_MINUTES),
+        "-delete"
+    ]);
    command_success_from_args([
        "find",
        COMPONENT_JOB_DIR,
@@ -1764,11 +1773,17 @@ function finish_component_job(path, component, action, exit_code, output_file) {
        ok = write_state_file(path, value);
    }
    else {
-        let raw_output = file_last_nonblank_line_value(output_file, "Failed to execute", 240);
+        // No JSON at all means the worker really did die before printing its
+        // result. Its stderr, kept out of the result channel above, holds the
+        // reason; fall back to the result file only if stderr is empty.
+        let raw_output = file_last_nonblank_line_value(output_file + ".stderr", "", 240);
+        if (raw_output == "")
+            raw_output = file_last_nonblank_line_value(output_file, "Failed to execute", 240);
        ok = write_state_file(path, component_fallback_job_state(component, action, raw_output, exit_code, updated_at));
    }

    remove_file(output_file);
+    remove_file(output_file + ".stderr");
    remove_file(output_file + ".json");
    return ok;
 }
@@ -1799,6 +1814,11 @@ function launch_component_worker(args) {

 function component_action_worker(state_file, output_file, component, action) {
    component = normalize_component_name(component);
+    // stderr gets its own file instead of being merged into the result channel.
+    // Merging put apk/opkg warnings and init-script chatter into the same file as
+    // the JSON result - the whole-file parse then failed, the line scan found no
+    // object, and a successful action was reported to the UI as "Failed to
+    // execute" with the tail of a log as its message.
    let command = command_env(component_worker_env()) + " " +
        command_from_args([
            "ucode",
@@ -1807,7 +1827,7 @@ function component_action_worker(state_file, output_file, component, action) {
            "component-action",
            as_string(component),
            as_string(action)
-        ]) + " >" + shell_quote(output_file) + " 2>&1";
+        ]) + " >" + shell_quote(output_file) + " 2>" + shell_quote(output_file + ".stderr");
    let status = command_status(command);

    finish_component_job(state_file, component, action, status, output_file);
@@ -1896,7 +1916,7 @@ function run_automatic_component_update_check(component) {
            "component-action",
            as_string(component),
            "check_update"
-        ]) + " >" + shell_quote(output_file) + " 2>&1";
+        ]) + " >" + shell_quote(output_file) + " 2>/dev/null";
    let status = command_status(command);
    let value = output_json_object(output_file);
    remove_file(output_file);
@@ -77,6 +77,19 @@ function command_output_from_args(args) {
    return command_output(command_from_args(args));
 }

+// Like command_output but keeps stdout regardless of the exit status. popen()'s
+// close() yields a raw wait status, so a command that prints a good answer and
+// then exits non-zero - or is signalled - loses all of it above.
+function command_output_lenient(command) {
+    let pipe = fs.popen(command, "r");
+    if (!pipe)
+        return "";
+
+    let data = pipe.read("all");
+    pipe.close();
+    return data != null ? as_string(data) : "";
+}
+
 function command_status(command) {
    let status = int(system(command));
    if (status == -1)
@@ -207,8 +220,12 @@ function first_line_last_field(value) {
    return length(fields) > 0 ? as_string(fields[length(fields) - 1]) : "";
 }

+// The version string is taken from stdout whatever the exit status: sing-box
+// prints "sing-box version X" first and may still exit non-zero (a warning about
+// a missing config, a signal from a concurrent service stop). Gating on the exit
+// code made the dashboard fall back to "unknown" for a perfectly working binary.
 function sing_box_version_output() {
-    return command_exists("sing-box") ? command_output_from_args([ "sing-box", "version" ]) : "";
+    return command_exists("sing-box") ? command_output_lenient(command_from_args([ "sing-box", "version" ]) + " 2>/dev/null") : "";
 }

 function sing_box_marker_is(value) {
@@ -0,0 +1,133 @@
+#!/usr/bin/env bash
+set -eo pipefail
+
+# A component action prints its JSON result to stdout and logs to syslog, but the
+# worker used to redirect stderr into the same file with 2>&1. Anything a child
+# wrote to stderr after the result - apk warnings, init-script chatter from the
+# restart that a Tachyon self-update performs on itself - landed after the JSON.
+# The whole-file parse then failed, the line scan found no object, and a
+# successful action was reported to the UI as a failure whose message was the
+# tail of a log ("Failed to execute").
+
+ROOT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)"
+UPDATES_UC="$ROOT_DIR/tachyon/files/usr/lib/components/updates.uc"
+ACTION_UC="$ROOT_DIR/tachyon/files/usr/lib/components/action.uc"
+SINGBOX_UC="$ROOT_DIR/tachyon/files/usr/lib/singbox/runtime.uc"
+
+fail() {
+  printf 'FAIL: %s\n' "$1" >&2
+  exit 1
+}
+
+# Comments mention 2>&1 to explain the bug; only real redirections count.
+code_only() {
+  sed 's://.*::'
+}
+
+worker="$(sed -n '/^function component_action_worker/,/^}/p' "$UPDATES_UC" | code_only)"
+[ -n "$worker" ] || fail "components/updates.uc must define component_action_worker"
+
+if grep -Fq '2>&1' <<<"$worker"; then
+  fail "component_action_worker must not merge stderr into the result file; stray stderr corrupts the JSON the UI parses"
+fi
+grep -Fq '".stderr"' <<<"$worker" ||
+  fail "component_action_worker must redirect stderr to a separate .stderr file"
+
+# The automatic check runs the same action module and parses the same way.
+auto="$(sed -n '/^function run_automatic_component_update_check/,/^}/p' "$UPDATES_UC" | code_only)"
+[ -n "$auto" ] || fail "components/updates.uc must define run_automatic_component_update_check"
+if grep -Fq '2>&1' <<<"$auto"; then
+  fail "run_automatic_component_update_check must not merge stderr into the file it json-parses"
+fi
+
+# The stderr file must be cleaned up with the rest of the job, and it is the
+# better source for a failure message than the (empty) result file.
+finish="$(sed -n '/^function finish_component_job/,/^}/p' "$UPDATES_UC" | code_only)"
+[ -n "$finish" ] || fail "components/updates.uc must define finish_component_job"
+grep -Fq 'remove_file(output_file + ".stderr")' <<<"$finish" ||
+  fail "finish_component_job must remove the worker .stderr file"
+grep -Fq 'output_file + ".stderr"' <<<"$finish" ||
+  fail "finish_component_job should report the worker stderr as the failure message"
+
+# A worker killed mid-run leaves its .stderr behind; the orphan sweep must take
+# it too, or the files pile up in tmpfs.
+grep -Fq 'remove_file(output_path + ".stderr")' "$UPDATES_UC" ||
+  fail "the component job sweep must remove orphaned .stderr files"
+grep -Fq '"*.out.stderr"' "$UPDATES_UC" ||
+  fail "the age-based orphan cleanup must cover *.out.stderr"
+
+# --- validation must judge sing-box by its output, not its exit status ---------
+#
+# `sing-box version` prints the version and can still exit non-zero or be
+# signalled by the service stop that precedes the install. command_output()
+# discards stdout whenever the raw wait status is non-zero, so validation saw an
+# empty string, declared a working binary broken and rolled the install back with
+# exit_code 129 (128+SIGHUP).
+
+probe="$(sed -n '/^function read_sing_box_binary_version/,/^}/p' "$ACTION_UC" | code_only)"
+[ -n "$probe" ] || fail "components/action.uc must define read_sing_box_binary_version"
+grep -Fq 'command_output_lenient(' <<<"$probe" ||
+  fail "read_sing_box_binary_version must keep stdout regardless of exit status"
+if grep -Eq '[^_]command_output\(' <<<"$probe"; then
+  fail "read_sing_box_binary_version must not use the status-gated command_output"
+fi
+
+version_output="$(sed -n '/^function sing_box_version_output/,/^}/p' "$SINGBOX_UC" | code_only)"
+[ -n "$version_output" ] || fail "singbox/runtime.uc must define sing_box_version_output"
+grep -Fq 'command_output_lenient(' <<<"$version_output" ||
+  fail "sing_box_version_output must keep stdout regardless of exit status"
+
+# ucode does not hoist: the helper must be declared before every call site.
+for file in "$ACTION_UC" "$SINGBOX_UC"; do
+  decl="$(grep -n '^function command_output_lenient' "$file" | head -1 | cut -d: -f1)"
+  [ -n "$decl" ] || fail "$file must declare command_output_lenient"
+  # Every mention that is not the declaration itself is a call site.
+  first_use="$(sed 's://.*::' "$file" | grep -n 'command_output_lenient(' |
+    grep -v ':function ' | head -1 | cut -d: -f1)"
+  [ -n "$first_use" ] || fail "$file declares command_output_lenient but never calls it"
+  [ "$decl" -lt "$first_use" ] ||
+    fail "$file declares command_output_lenient at line $decl but calls it at $first_use; ucode does not hoist"
+done
+
+# --- behavioural: the helper really survives a non-zero exit ------------------
+
+if command -v ucode >/dev/null 2>&1; then
+  WORK_DIR="$(mktemp -d)"
+  trap 'rm -rf "$WORK_DIR"' EXIT
+
+  cat >"$WORK_DIR/probe.uc" <<'UC'
+import * as fs from "fs";
+
+function command_output(command) {
+    let pipe = fs.popen(command, "r");
+    if (!pipe)
+        return "";
+    let data = pipe.read("all");
+    let status = pipe.close();
+    if (status != 0 || data == null)
+        return "";
+    return "" + data;
+}
+
+function command_output_lenient(command) {
+    let pipe = fs.popen(command, "r");
+    if (!pipe)
+        return "";
+    let data = pipe.read("all");
+    pipe.close();
+    return data != null ? "" + data : "";
+}
+
+let cmd = "printf 'sing-box version 1.13.18-extended-2.6.3\\n'; exit 1";
+print("strict=[" + trim(command_output(cmd)) + "]\n");
+print("lenient=[" + trim(command_output_lenient(cmd)) + "]\n");
+UC
+
+  out="$(ucode -R "$WORK_DIR/probe.uc")"
+  grep -Fq 'strict=[]' <<<"$out" ||
+    fail "sanity: status-gated command_output was expected to drop the output, got: $out"
+  grep -Fq 'lenient=[sing-box version 1.13.18-extended-2.6.3]' <<<"$out" ||
+    fail "command_output_lenient must return stdout of a command that exits non-zero, got: $out"
+fi
+
+printf 'component worker output channel checks passed\n'