From 99e8c2c0910f2a037535c2c5a1fb3434aadfa7ce Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 8 Oct 2026 06:55:04 +0000 Subject: [PATCH 01/15] fix(run): tolerate btime truncation in the session pid-reuse guard MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit SessionMembers rebuilt a process's start time as btime + starttime and skipped it if that fell more than 1s before notBefore. btime is whole seconds (up to 1s early) and starttime whole ticks (up to 10ms early), so the rebuild runs up to ~1.01s early: a process started a few ms after notBefore was skipped. frac(btime) is fixed per machine, so on a VM that booted late in a second every session lookup missed a run's own leader — `run stop` reporting "was not running" for a live run, and TestRunStop_* / TestSessionMembers_* failing together on CI (runs 37733157296, 37688181946) while green elsewhere. The comparison is now startedBefore with a 2s slack; a reused pid comes from a session that began long before, never seconds. The new test pins the worst case (boot at X.9999, start 9.9ms into a tick, 1ms after notBefore) and fails against the 1s slack. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01P65SqmwwvbWdJVRwhYiMQw --- .../skills/fix-issue/findings/cmd-mxcli.jsonl | 1 + CHANGELOG.md | 1 + cmd/mxcli/docker/session_linux.go | 27 ++++++++++++++----- cmd/mxcli/docker/session_linux_test.go | 24 +++++++++++++++++ 4 files changed, 46 insertions(+), 7 deletions(-) diff --git a/.claude/skills/fix-issue/findings/cmd-mxcli.jsonl b/.claude/skills/fix-issue/findings/cmd-mxcli.jsonl index b6fb95bab..164aef13f 100644 --- a/.claude/skills/fix-issue/findings/cmd-mxcli.jsonl +++ b/.claude/skills/fix-issue/findings/cmd-mxcli.jsonl @@ -168,3 +168,4 @@ {"area": "cmd/mxcli", "date": "2026-10-05", "symptom": "`mxcli run --local --watch`: a model change made while the app is still booting is never built — the app keeps serving the model from before it, `--watch` logs no `Change detected`, and a waiter on the change times out. Re-running the exec does nothing (byte-idempotent: it writes nothing, so nothing re-triggers the watcher)", "cause": "watchAndApply took its baseline `last := sourceMTime(...)` after the boot finished, so an edit landing between the boot build's model read and the watch loop's start was already folded into the baseline", "file": "`cmd/mxcli/docker/runlocal.go` (`RunLocal` bootSource, `watchAndApply`)", "insight": "A watcher's baseline must be the source time the last build was MADE FROM, taken before that build — not 'now' when the watcher starts. Same class as the earlier fix that stopped moving the baseline to time.Now() after an apply. Measured with the run-lifecycle integration test: exec a page while the detached run's state says the boot build is in progress; with the old baseline `run wait` times out after 2m (no build #2), with the fix it reports `applied: build #2 via reload`. Exposed by making `run wait` race-free on source time: a generation-counting wait could not have told the change was lost.", "refs": ["cmd_run_lifecycle_integration_test.go"]} {"area": "cmd/mxcli", "date": "2026-10-06", "symptom": "`mxcli run --local --watch` on Mendix 10.24 / 11.6 dies after 5 minutes with `starting web client bundler: web client watcher timed out after 5m0s`, while the bundler's own log says `Bundling finished in 8999 milliseconds` — the bundle was done in 9s", "cause": "`parseBundlerStatus` (`cmd/mxcli/docker/webclient_watch.go`) only understood the modern-web-bundler protocol (`{\"protocol\":\"mx-modern-web-bundler\",\"type\":\"status\",\"payload\":{\"kind\":…}}`). The rollup-runner.mjs shipped with 10.24 and 11.6 predates it and writes `{\"code\":\"START\"|\"SUCCESS\"|\"ERROR\",\"payload\":…}` (ERROR payload an object with `message`, or a bare string when the config fails to load). Every status line was dropped as plain logging, so the first-build wait never saw a success", "file": "cmd/mxcli/docker/webclient_watch.go", "insight": "--watch had never worked on these versions: the parser has accepted only the new protocol since it was written (#349). Nothing exercised the watcher below 11.12 until the run-lifecycle integration test reached the nightly matrix — and it reached it only because ResolveMxForVersion substitutes ANY cached mxbuild for the test's default 11.13.0, so each matrix leg ran it against its own version. The runner's protocol is part of the mxbuild version contract: read tools/node/rollup-runner.mjs of the oldest supported version before assuming a stdout shape. Control: the lifecycle test on 11.6.8 with the parser reverted fails with the nightly's exact timeout (MXCLI_WEB_CLIENT_TIMEOUT=60s makes it fail in a minute); with the fix it passes", "refs": ["nightly 2026-10-06 (ako/mxcli run 37437089065, mendixlabs/mxcli run 37437605368)"]} {"area": "cmd/mxcli", "date": "2026-10-06", "symptom": "`mxcli syntax rename` printed `Unknown topic: rename` and `mxcli syntax --json` had rename only for attributes, values and definitions, while `RENAME MICROFLOW TO ;` passed `mxcli check` and `mxcli help rename` documented it; an agent concluded MDL could not rename a microflow and copied, re-pointed and deleted it by hand", "cause": "The renameStatement rule (MDLParser.g4) and its executor (mdl/executor/cmd_rename.go) never got a SyntaxFeature in cmd/mxcli/syntax/; the only discovery path was the cobra `rename` subcommand's Long text, which `syntax` does not read. BySegmentMatch could not rescue it because no registered path has a `rename` segment", "file": "cmd/mxcli/syntax/features_misc.go", "insight": "Same class as the TABCONTAINER gap (widget_keywords_drift_test.go): an agent treats absence from `mxcli syntax` as absence from the language, so a statement the grammar accepts but the registry omits is effectively missing. Fixed with a `rename` topic plus a guard (rename_topic_test.go) that reads the renameTarget rule from the .g4 and requires every alternative in the topic, and see_also links from microflow/page/entity/move. The CLI subcommand and the MDL statement diverge (MDL also takes JAVA ACTION and WORKFLOW); the topic says so rather than implying parity. Control: with the topic reverted the built binary prints `Unknown topic: rename` verbatim and TestSyntaxRenameTopic fails; dropping the RENAME WORKFLOW line fails the grammar guard. A sweep for other top-level statements with no topic would be the cheap next step", "refs": ["mendixlabs/mxcli#1318"]} +{"area": "cmd/mxcli", "date": "2026-10-08", "symptom": "Main's build-and-test fails intermittently in the run-lifecycle tests, several at once in one run and green on the next: TestRunStop_LeavesNoOrphanBehind (\"fake run has 0 session members, want the leader and its child\"), TestRunStop_ReapsTheLeftoversOfAKilledRun, TestSessionMembers_FindsOrphanedGrandchild (\"members … = [], want the leader and its sleep\"). Not reproducible locally (20/20 green). In real use the same path makes `run stop` / `run status` miss a live run's processes.", "cause": "docker.SessionMembers' pid-reuse guard rebuilt a process's start time as btime + starttime/USER_HZ and dropped it if that fell more than 1s before notBefore. btime in /proc/stat is whole seconds (up to 1s early) and starttime whole 10ms ticks (up to 10ms early), so the rebuild can be ~1.01s early: a process started a few ms after notBefore was dropped. frac(btime) is fixed for a machine's uptime, so a CI VM booted late in a second failed every such test in the run, and others never did; a process started a few ms later (the leader's sleep) survived.", "file": "`cmd/mxcli/docker/session_linux.go` (`startedBefore`, `startSlack` = 2s)", "insight": "A flake that fails a whole family of tests in one run and none in the next points at per-machine state, not timing within the test: here the fractional second of the VM's boot. Make the comparison a pure function and pin the worst case (boot at X.9999, start 9.9ms into a tick, 1ms after notBefore); the test then fails deterministically against the old slack. Rebuilding a wall-clock time from btime + ticks loses up to 1s + 1 tick; any slack must exceed both.", "refs": ["https://github.com/ako/mxcli/actions/runs/37733157296", "https://github.com/ako/mxcli/actions/runs/37688181946"]} diff --git a/CHANGELOG.md b/CHANGELOG.md index 24fa17944..cb696abae 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -26,6 +26,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/). ### Fixed +- **`run stop` and `run status` find a detached run's processes on every machine** — the guard against a reused session id rebuilt each process's start time from the kernel's boot time, which is whole seconds, and allowed only one second of slack. On a machine that booted late in a second, a run's own processes read as older than the run and were skipped, so `run stop` could report "was not running" for a live run. The slack is now two seconds. This was also the intermittent `TestRunStop_*` / `TestSessionMembers_*` failure on CI. - **The catalog names a call's and a delete's target** (mendixlabs/mxcli#1305) — `activities_for()` and `CATALOG.ACTIVITIES` returned every microflow, nanoflow, Java action and JavaScript action call with `action_ref=""`, and every delete with `entity_ref=""`, although `refs_from()` had both targets; a loop-scoped lint rule could not follow a call out of the loop. `action_ref` / `ActionRef` is now the called document, `entity_ref` / `EntityRef` a delete's entity (when the flow types the variable: a parameter, a create or retrieve output, a loop iterator), and the new `queue_ref` / `QueueRef` the task queue a microflow or Java action call runs in, so a rule can skip a call that runs asynchronously. A nanoflow's JavaScript action call now has a `refs_from()` `call` row (`target_type` `"JAVASCRIPT_ACTION"`), so `show callers` sees it. The catalog schema is bumped to 23; a cached catalog rebuilds. - **A DataGrid 2 column's `Visible:` expression is written** — `Visible: $showPrices`, `Visible: if … then … else …`, `visible: not(…)` and `Visible: [cond]` on a column passed `check` and `exec` and were stored as `true`, so the column was always visible; only the old quoted `Visible: ''` was kept. `alter page … set (Visible: ) on grid column(…)` was refused as "column property VisibleIf not found", and an inserted column dropped `Visible: false` too. `describe` now prints the bare expression. A column's visibility is evaluated once for the grid, with no row object, so `$currentObject` there is CE0117 at build; `check` refuses it as **MDL-WIDGET43** (measured on 11.14.0). Use a page variable or parameter. Projects regenerate their widget definitions (generator version 18). - **`set $Param = …` on a parameter is refused** — a Change variable cannot target a parameter, and mxbuild rejects it with CE7247 "Parameter 'N' cannot be changed." (measured on 11.14.0 for Integer and String parameters in a microflow, a nanoflow and a rule). `check` and `exec` passed it. MDL-SET01 now refuses it for every parameter but a list (`set` on a list parameter is a Change list Replace, which builds), and `exec` enforces the rule. Copy the parameter into a variable first: `declare $Value Integer = $N;`. diff --git a/cmd/mxcli/docker/session_linux.go b/cmd/mxcli/docker/session_linux.go index 5d455df3b..128a1360f 100644 --- a/cmd/mxcli/docker/session_linux.go +++ b/cmd/mxcli/docker/session_linux.go @@ -55,19 +55,32 @@ func SessionMembers(sid int, notBefore time.Time) []int { if !ok || st.session != sid || st.state == "Z" { continue } - if !notBefore.IsZero() && !boot.IsZero() { - started := boot.Add(time.Duration(st.startTicks) * time.Second / clockTicks) - // One second of slack: starttime has tick resolution, notBefore - // wall-clock resolution. - if started.Before(notBefore.Add(-time.Second)) { - continue - } + if !notBefore.IsZero() && !boot.IsZero() && startedBefore(boot, st.startTicks, notBefore) { + continue } out = append(out, pid) } return out } +// startSlack is how far before notBefore a rebuilt start time may fall and +// still count. The rebuild is btime + starttime: btime is whole seconds (up to +// 1s early) and starttime whole ticks (up to 10ms early), and the kernel's +// boot-time arithmetic and Go's wall clock can disagree by a little more. The +// previous 1s covered the first alone, so on a machine whose boot fell late in +// a second a run's own leader read as older than the run and was dropped: +// `run stop` saw nothing to stop. Fixed per machine, not per call — such a CI +// VM failed every session test in the run. Pid reuse, which this guards +// against, comes from a session that started long before, never seconds. +const startSlack = 2 * time.Second + +// startedBefore reports whether a process whose stat starttime is startTicks +// began before notBefore, beyond startSlack. +func startedBefore(boot time.Time, startTicks int64, notBefore time.Time) bool { + started := boot.Add(time.Duration(startTicks) * time.Second / clockTicks) + return started.Before(notBefore.Add(-startSlack)) +} + // procStat is the part of /proc//stat SessionMembers needs. type procStat struct { state string diff --git a/cmd/mxcli/docker/session_linux_test.go b/cmd/mxcli/docker/session_linux_test.go index 14bbe2242..79cab715f 100644 --- a/cmd/mxcli/docker/session_linux_test.go +++ b/cmd/mxcli/docker/session_linux_test.go @@ -57,3 +57,27 @@ func TestSessionMembers_FindsOrphanedGrandchild(t *testing.T) { t.Errorf("start-time guard let %v through", got) } } + +// The pid-reuse guard rebuilds a start time from btime (whole seconds, so up +// to 1s early) plus starttime (10ms ticks, so up to 10ms early). A process +// that started just after notBefore must still count as this run's: with only +// 1s of slack it fell out whenever the two truncations added up to more, +// which made SessionMembers return nothing for a live run — `run stop` +// reporting "was not running", and three tests here failing on CI a few +// percent of the time. +func TestStartedBefore_ToleratesBtimeAndTickTruncation(t *testing.T) { + realBoot := time.Unix(1000, 999_900_000) // btime reads 1000 + btime := time.Unix(1000, 0) + // A start 9.9ms into a tick, 1ms after notBefore: truncation takes off + // 0.9999s + 9.9ms, more than the old 1s of slack plus the 1ms gap. + notBefore := realBoot.Add(50*time.Second + 8900*time.Microsecond) + actualStart := notBefore.Add(time.Millisecond) + ticks := int64(actualStart.Sub(realBoot) / (time.Second / clockTicks)) // truncated, as the kernel does + if startedBefore(btime, ticks, notBefore) { + t.Errorf("a process started %v after notBefore was taken for an earlier one (ticks %d)", actualStart.Sub(notBefore), ticks) + } + // The guard still does its job: a session that began long before is not this run's. + if !startedBefore(btime, ticks, notBefore.Add(time.Hour)) { + t.Error("a process from an hour before notBefore passed the guard") + } +} From 01d317667925aac646893ed7c05d5b26101c4c8f Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 8 Oct 2026 06:56:03 +0000 Subject: [PATCH 02/15] fix(make): give `make test` an explicit -timeout (mendixlabs/mxcli#1291) `make test` ran `go test ./...` with no -timeout, so every test binary got Go's 10m default. Under ./... all packages run at once and a package's wall time follows machine load: mdl/linter passes in ~25s alone and was measured at 552s and 872s inside `make test`, the latter failing with `panic: test timed out after 10m0s` in a package the PR had not touched. - test: `-timeout $(TEST_TIMEOUT)`, default 30m (twice the slowest measurement), overridable per run. - check-conformance / conformance-shrink: explicit -timeout 20m (88s alone). - scripts/check-test-timeouts.sh, wired into `make lint`: refuses any go test in the Makefile, direct or through a variable such as INTEGRATION_GO_TEST, without a -timeout, and fails if it cannot see the `test` target at all. - finding appended to findings/other.jsonl. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01RL7V4XDekBvPTYuKgF96sn --- .claude/skills/fix-issue/findings/other.jsonl | 1 + Makefile | 25 ++++-- scripts/check-test-timeouts.sh | 89 +++++++++++++++++++ 3 files changed, 110 insertions(+), 5 deletions(-) create mode 100755 scripts/check-test-timeouts.sh diff --git a/.claude/skills/fix-issue/findings/other.jsonl b/.claude/skills/fix-issue/findings/other.jsonl index 08773e43a..ac9134c61 100644 --- a/.claude/skills/fix-issue/findings/other.jsonl +++ b/.claude/skills/fix-issue/findings/other.jsonl @@ -21,3 +21,4 @@ {"area": "examples/doctype-tests", "date": "2026-09-22", "symptom": "The nightly fails on Mendix 10.24 only, in `TestMxCheck_DoctypeScripts/14-project-settings-examples.mdl`, with `Execution error: alter settings workflows add group '' requires Mendix 11.2.0+ (project is 10.24.24.119349)`. Push CI (single, newer version) and `TestDoctypeScriptsParseAfterVersionFiltering` both pass", "cause": "The workflow-groups feature (832e9c80) added Examples 4.3-4.7 to the doctype script ungated, although its executor correctly refuses the statement below 11.2 (`Settings$WorkflowGroup` is 11.2 metamodel). Third time this class has landed (Atlas building block in 15c, `DecimalScale`, now workflow groups)", "file": "`mdl-examples/doctype-tests/14-project-settings-examples.mdl`", "insight": "Wrap the examples in `-- @version: 11.2+` ... `-- @version: any`, with the directive ABOVE the first `/** */` comment. The parse-only guard cannot catch this: it proves the filtered script parses, not that the executor accepts every statement on that version, so a version-refused statement only surfaces in the nightly's 10.24 job. When a feature adds a version check to the executor, gate its doctype example in the same change. Reproduce locally in about 30s: `mxcli setup mxbuild --version 10.24.24.119349`, then `go test -tags integration ./mdl/executor/ -run 'TestMxCheck_DoctypeScripts/