diff --git a/CHANGELOG.md b/CHANGELOG.md index 48e471ad..e71acc36 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -19,6 +19,7 @@ Sections dated before 2026-09-19 predate the cycle and stay as they are. Named m ## Unreleased +- fix(exec): **the gate keeps mxbuild's full output in a per-run log and names it on screen and in the BUILD-LOG row.** exec.sh printed `head -20` of the output and deleted the rest, so the evidence of a failed gate (a CE1613 detail among it) was lost in a field migration project (12 modules). A gate that does not pass now writes `.mpr-snapshots/.mxbuild-logs/.log` (newest 30 kept; a dot dir, so `restore-mpr.sh` and the snapshot pruning skip it; a clean or delta-gate pass writes none, and a retry always keeps the first attempt's output next to the second); the screen shows the top lines plus the path and the row ends with `mxbuild log: `. Test: `tests/wave2/test-exec-gate-log.sh` (Refs #442, #448, #171, #285, #424) — field migration project - fix(exec): **the gate pauses this project's `mxcli run --local --watch` while mxbuild runs and retries once on an infra exit.** The gate's mxbuild and a live watcher both write `deployment/`; in a field migration project (12 modules) 17 of 27 failed gates were "gate could not run" (mxbuild exit 1, no CE code), against 0 of 22 in watcher-free copies. The watcher is stopped (SIGSTOP) for the gate and resumed (SIGCONT, also in the EXIT trap); an exit 1 or 3 with no CE code and no errors file is retried once and the BUILD-LOG row says `retry after infra exit`; a final failure still takes the #424 rollback. The match is exact (the watcher's project dir must equal this project's root, so a sibling `-copy` or a nested worktree watcher is never paused), and the paused pids are recorded in `.mpr-snapshots/.watcher-paused` so the next exec.sh resumes a watcher left stopped by a SIGKILLed one and says so. Test: `tests/wave2/test-exec-gate-retry.sh` (Refs #441, #444, #171, #285, #424) — field migration project - learn(load-test): **trap 9, an unlicensed local runtime caps concurrent sessions at 6 ("Maximum number of sessions exceeded!") and stops itself after a random 2 to 4 hours, both reading as the app failing under load; more than 6 users needs a licensed runtime or a cloud sandbox.** Text only, ondemand skill. Source: a personal licence-budget gate written after parallel journey runs hit both — MendixMau - fix(progress-report): **the full plan tables (one table per phase plus views A and B) now sit in one closed `
` card below the phase cards, so a large plan no longer pushes the rest of the report off screen; the phase cards above stay the summary, and nothing is written when the project has no plan fragment.** Test: P6 in `test-progress-report-polish.sh` — MendixMau diff --git a/project-bin/_common.sh b/project-bin/_common.sh index 7d853a22..0c376266 100755 --- a/project-bin/_common.sh +++ b/project-bin/_common.sh @@ -590,6 +590,8 @@ find_java_exe() { MXTK_PAUSED_PIDS="" MXTK_PAUSED_FILE="" MXTK_GATE_RETRY_NOTE="" +MXTK_GATE_FIRST_OUT="" +MXTK_GATE_FIRST_EXIT="" # mxtk_watcher_pids - pids of `mxcli run --local --watch` that belong to this # project. Exact match only: the watcher's project dir (the directory of its -p argument, @@ -680,11 +682,13 @@ mxtk_resume_leftover() { # on the model; a real model error always names a CE code. An errors file with content (for # example a version mismatch in errors[]) is deterministic and is not retried. # Prints nothing on stdout (callers discard the count); sets the same MXTK_MXBUILD_* globals as -# mxtk_mxbuild_error_count, plus MXTK_GATE_RETRY_NOTE ("retry after infra exit" or empty). +# mxtk_mxbuild_error_count, plus MXTK_GATE_RETRY_NOTE ("retry after infra exit" or empty); after a +# retry MXTK_GATE_FIRST_OUT / MXTK_GATE_FIRST_EXIT hold the FIRST attempt's output and exit code +# (the MXTK_MXBUILD_* globals describe the final attempt only). # Returns mxtk_mxbuild_error_count's code for the final attempt. mxtk_gate_mxbuild() { local _mpr="$1" _timeout="${2:-0}" _ef="$3" _rc=0 - MXTK_GATE_RETRY_NOTE="" + MXTK_GATE_RETRY_NOTE=""; MXTK_GATE_FIRST_OUT=""; MXTK_GATE_FIRST_EXIT="" mxtk_pause_watchers "${PROJECT_ROOT:-$(dirname "$_mpr")}" mxtk_mxbuild_error_count "$_mpr" "$_timeout" "$_ef" >/dev/null || _rc=$? case "${MXTK_MXBUILD_EXIT:-}" in @@ -692,6 +696,7 @@ mxtk_gate_mxbuild() { if [ ! -s "$_ef" ] && ! grep -Eq -- 'CE[0-9]{4}' <<<"${MXTK_MXBUILD_OUT:-}"; then echo " ⚠ retry after infra exit: mxbuild exited $MXTK_MXBUILD_EXIT with no CE code and no errors file; building once more" >&2 MXTK_GATE_RETRY_NOTE="retry after infra exit" + MXTK_GATE_FIRST_OUT="${MXTK_MXBUILD_OUT:-}"; MXTK_GATE_FIRST_EXIT="$MXTK_MXBUILD_EXIT" : > "$_ef" _rc=0 mxtk_mxbuild_error_count "$_mpr" "$_timeout" "$_ef" >/dev/null || _rc=$? diff --git a/project-bin/exec.sh b/project-bin/exec.sh index 5c04df38..81288802 100755 --- a/project-bin/exec.sh +++ b/project-bin/exec.sh @@ -437,6 +437,7 @@ BUILD_LOG="$PROJECT_ROOT/docs/BUILD-LOG.md" GATE_STATE="not-run" # not-run | skipped | unverified | pass | fail GATE_ERRORS="?" # mxbuild error count behind a pass (0 = clean); recorded in the stamp MXB_WHY="" # mxbuild's errors[] reason when it exited without checking the model +MXB_LOG_NOTE="" # "mxbuild log: " when the gate's full output was saved (BUILD-LOG detail) GATE_NOTE="" # "retry after infra exit" when a gate mxbuild was run twice # ── Exec approval (auto records itself) ────────────────────────────────────── @@ -491,7 +492,7 @@ HDR2 # The gate cell is read from GATE_STATE rather than passed in, so no caller # can omit it — a blank cell in this table reads as "fine", which is the exact # false-green the gate exists to prevent. - _detail="$2${CHANGE_CLASS:+ · change: $CHANGE_CLASS}${CR_ID:+ · cr: $CR_ID}${SCAN_NOTE:+ · $SCAN_NOTE}${GATE_NOTE:+ · $GATE_NOTE}${HV_NOTE:+ · $HV_NOTE}$_EXEC_APPROVAL_SUFFIX${STEP_TIMES:+ · steps: $STEP_TIMES}" + _detail="$2${CHANGE_CLASS:+ · change: $CHANGE_CLASS}${CR_ID:+ · cr: $CR_ID}${SCAN_NOTE:+ · $SCAN_NOTE}${GATE_NOTE:+ · $GATE_NOTE}${MXB_LOG_NOTE:+ · $MXB_LOG_NOTE}${HV_NOTE:+ · $HV_NOTE}$_EXEC_APPROVAL_SUFFIX${STEP_TIMES:+ · steps: $STEP_TIMES}" printf '| %s | `%s` | %s | %s | %s |\n' \ "$(date '+%Y-%m-%dT%H:%M:%S%z')" "$LOG_NAME" \ "${GATE_STATE:-not-run}" "$1" "$_detail" >> "$BUILD_LOG" @@ -1643,12 +1644,46 @@ if [ -x "$MXBUILD" ] && [ -x "$JAVA_EXE" ]; then MXB_WHY="${MXTK_MXBUILD_WHY:-}" step_done gate + # Keep the gate's full mxbuild output when the gate did not pass. The screen shows only the + # top lines (the failure detail is often in the tail), and the temp file behind + # mxtk_mxbuild_error_count is gone by now, so without this the evidence of a failed gate was + # lost (a field migration project lost the detail of a CE1613 this way). mxbuild prints output + # on a clean build too, so the log is written from the failure branches below (mxb_log_hint) + # and never for a pass, a delta-gate pass over pre-existing errors included. The one exception + # is a retry: the first attempt's output is the evidence of the infra exit, so a retry always + # leaves a log, with both attempts in it. One file per run, under .mpr-snapshots/.mxbuild-logs/, + # the newest 30 kept. The DOT in the name is load-bearing: restore-mpr.sh (no argument picks + # the newest) and snapshot-mpr.sh (keeps 5) glob `.mpr-snapshots/*/`, which skips dot dirs. + # Its project-relative path goes on screen and in the row. + MXB_LOG_REL="" + mxb_save_log() { + [ -z "$MXB_LOG_REL" ] || return 0 + [ -n "$MXBUILD_OUT$MXTK_GATE_FIRST_OUT" ] || return 0 + _MXB_LOG_DIR="$PROJECT_ROOT/.mpr-snapshots/.mxbuild-logs" + MXB_LOG_REL=".mpr-snapshots/.mxbuild-logs/$(date +%Y%m%d-%H%M%S)-$$.log" + if mkdir -p "$_MXB_LOG_DIR" 2>/dev/null && { + if [ -n "$MXTK_GATE_RETRY_NOTE" ]; then + printf '=== attempt 1 (exit %s, infra failure, retried) ===\n%s\n=== attempt 2 (final, exit %s) ===\n%s\n' \ + "$MXTK_GATE_FIRST_EXIT" "$MXTK_GATE_FIRST_OUT" "$MXBUILD_EXIT" "$MXBUILD_OUT" + else + printf '%s\n' "$MXBUILD_OUT" + fi > "$PROJECT_ROOT/$MXB_LOG_REL"; } 2>/dev/null; then + MXB_LOG_NOTE="mxbuild log: $MXB_LOG_REL" + ls -t "$_MXB_LOG_DIR"/*.log 2>/dev/null | sed -n '31,$p' | while IFS= read -r _old; do rm -f "$_old"; done + else + MXB_LOG_REL="" + fi + } + mxb_log_hint() { mxb_save_log; [ -z "$MXB_LOG_REL" ] || echo " full mxbuild output: $MXB_LOG_REL"; } + if [ -n "$MXTK_GATE_RETRY_NOTE" ]; then mxb_save_log; fi + if [ -f "$ERRORS_FILE" ] && [ -s "$ERRORS_FILE" ]; then CE_COUNT=$(err_count "$ERRORS_FILE") if [ "$CE_COUNT" = "?" ]; then GATE_STATE="unverified" echo " ⚠ mxbuild errors file could not be parsed — check manually." echo "$MXBUILD_OUT" | grep -v "^$\|icon\|Microsoft\|Assembly\|__" | head -10 || true + mxb_log_hint elif [ "$CE_COUNT" = "0" ] && [ "$MXBUILD_EXIT" -ne 0 ]; then # Non-empty errors file, 0 Error problems, NON-ZERO exit: mxbuild never checked the # model. The reason sits in errors[], which err_count does not read, e.g. (verbatim, @@ -1662,6 +1697,7 @@ if [ -x "$MXBUILD" ] && [ -x "$JAVA_EXE" ]; then echo " ✗ mxbuild exited $MXBUILD_EXIT and listed 0 model problems — it did NOT check the model." echo " ${MXB_WHY:-no reason in errors[]; mxbuild output follows}" [ -z "$MXB_WHY" ] && { echo "$MXBUILD_OUT" | grep -v "^$\|icon\|Microsoft\|Assembly\|__" | tail -10 || true; } + mxb_log_hint echo " A version mismatch is fixed by the matching mxbuild: ./mxcli setup mxbuild -p $MPR_BASE" echo " (find_mxbuild prefers it once cached), or MXBUILD_PATH=." elif [ "$CE_COUNT" = "0" ]; then @@ -1711,6 +1747,7 @@ if [ -x "$MXBUILD" ] && [ -x "$JAVA_EXE" ]; then rm -f "$ERRORS_FILE" else GATE_STATE="fail" + mxb_save_log CE_CODES=$(err_codes "$ERRORS_FILE") read -r NEW_COUNT NEW_CODES <.log when the +# gate does not pass; the screen shows the top lines plus the log path, and the BUILD-LOG row +# names the log. The dir is a dot dir so restore-mpr.sh and snapshot-mpr.sh never see it. +# +# A mxbuild fails with a long output: the log holds the whole output (including the tail the +# screen cut off), the screen names the path, the row names the path [guard: survives rollback] +# B a clean run WITH mxbuild output writes no log and the row has no log note [guard] +# B2 a delta-gate pass over pre-existing errors writes no log either +# C only the newest 30 logs are kept +# D an infra exit that a retry cures still leaves the first attempt's log, both attempts +# separated, and the row says so; two infra exits log both attempts too +# E after a failed gate restore-mpr.sh with no argument restores the real newest snapshot, +# and an exec through the real snapshot-mpr.sh (keep 5) does not delete the logs dir +# +# Synthetic only: throwaway git repo, stub mxcli, stub mxbuild, stub java. Nothing real runs. +set -uo pipefail + +TOOLKIT="$(cd "$(dirname "${BASH_SOURCE[0]}")/../.." && pwd)" +SUBJECT="${1:-$TOOLKIT/project-bin/exec.sh}" +case "$SUBJECT" in /*) ;; *) SUBJECT="$PWD/$SUBJECT" ;; esac +WORK="$(cd "$(mktemp -d "${TMPDIR:-/tmp}/exec-gatelog.XXXXXX")" && pwd -P)" || exit 2 +trap 'rm -rf "$WORK"' EXIT +PASS=0; FAIL=0 +ok() { PASS=$((PASS+1)); echo " ok - $1"; } +bad() { FAIL=$((FAIL+1)); echo " FAIL - $1${2:+: $2}"; } +echo "== subject: $SUBJECT" + +P="$WORK/proj" +mkdir -p "$P/bin" "$P/mprcontents" "$P/mdlsource" "$WORK/jdk/bin" +printf 'not a real model\n' > "$P/Fixture.mpr" +printf 'bson\n' > "$P/mprcontents/a.mxunit" +printf 'CREATE MODULE "Nope";\n' > "$P/mdlsource/test.mdl" +cp "$TOOLKIT/project-bin/_common.sh" "$TOOLKIT/project-bin/restore-mpr.sh" "$P/bin/" +cp "$SUBJECT" "$P/bin/exec.sh" +cat > "$P/bin/snapshot-mpr.sh" <<'SNAP' +#!/usr/bin/env bash +set -e +cd "$(dirname "$0")/.." +D=".mpr-snapshots/$(date +%Y%m%d-%H%M%S)-$$-$RANDOM" +mkdir -p "$D"; cp Fixture.mpr "$D/"; cp -r mprcontents "$D/" +echo "Snapshot saved: $D" +SNAP +# The write: `mxcli exec` appends to the model, as a real script would. +cat > "$P/mxcli" <<'MXCLI' +#!/usr/bin/env bash +D="$(cd "$(dirname "$0")" && pwd)" +case "${1:-}" in + check) exit 0 ;; + exec) echo "written by the script" >> "$D/Fixture.mpr"; echo "x" >> "$D/mprcontents/a.mxunit"; echo "fake mxcli exec"; exit 0 ;; +esac +exit 0 +MXCLI +chmod +x "$P/bin/"*.sh "$P/mxcli" +# mxbuild: MXB_MODES per call number, comma list: ok (prints output, as the real one does) | +# long (exit 137, 40 lines of output, no errors file) | infra (exit 1, no CE code, no errors file) | +# err (a CE0001 error list, exit 1, with output) +cat > "$WORK/mxbuild" <<'MXB' +#!/usr/bin/env bash +n=$(( $(cat "$MXB_N" 2>/dev/null || echo 0) + 1 )); echo "$n" > "$MXB_N" +mode="$(printf '%s\n' "$MXB_MODES" | tr ',' '\n' | sed -n "${n}p")"; mode="${mode:-ok}" +err=""; for a in "$@"; do case "$a" in --write-errors=*) err="${a#--write-errors=}" ;; esac; done +case "$mode" in + ok) echo "Build started"; echo "Deploying"; echo "Build finished"; [ -n "$err" ] && printf '{"problems":[]}' > "$err"; exit 0 ;; + infra) echo "Directory not empty : deployment/web"; exit 1 ;; + long) i=1; while [ "$i" -le 40 ]; do echo "mxbuild output line $i"; i=$((i+1)); done; echo "TAIL-MARKER the real failure detail"; exit 137 ;; + err) echo "mxbuild reports errors"; [ -n "$err" ] && printf '{"problems":[{"severity":"Error","code":"CE0001","message":"boom","element":{"document":"M.X"}}]}' > "$err"; exit 1 ;; +esac +MXB +printf '#!/usr/bin/env bash\nexit 0\n' > "$WORK/jdk/bin/java" +chmod +x "$WORK/mxbuild" "$WORK/jdk/bin/java" +( cd "$P" && git init -q . && printf '.mpr-snapshots/\ndocs/\n.claude/\n' > .gitignore && git add -A \ + && git -c user.email=t@t -c user.name=t commit -qm fixture ) >/dev/null 2>&1 + +LOG="$P/docs/BUILD-LOG.md" +sum() { cat "$P/Fixture.mpr" "$P/mprcontents/a.mxunit" | cksum; } +BEFORE="$(sum)" # the committed model; run() resets to it +# run