`show references` / `search` / `show callers` rebuild a stale source-mode catalog inside the 5m statement guard; the timeout discards the build, so every call repeats it

[kaspergff]

1. mxcli version: nightly-20261007-a924d11b7 (Windows 11, amd64); also seen on v0.25.0
2. Mendix version: 11.12.5
Repro app: a fresh mxcli new app, built by the script below

3. Scenario

If the cached catalog is in source mode and the .mpr changes, show references, show callers, show impact and search rebuild the catalog themselves (ensureCatalog(ctx, true)). Since #1081 that rebuild runs at the cached mode, so it is a source build, although these statements only need full mode. The rebuild runs inside the statement, under the default 5-minute wall-clock guard. That guard exempts only RefreshCatalogStmt (#651). On a large app the source build takes longer than 5 minutes, so the statement times out before the cache is saved. The next call finds the same stale cache and starts the same rebuild, so it fails the same way. In practice, show references stops working on that app until someone runs refresh catalog explicitly or sets MXCLI_EXEC_TIMEOUT.

On an app with 3032 documents (1750 microflows), an implicit source rebuild took more than 5 minutes. It failed with statement timed out after 5m0s at document 1110 of 3032, and the cache stayed unchanged. An explicit refresh catalog full source of the same app takes 7m55s, and a full build takes 30–95 s. A fresh app builds in about a second, so the script uses MXCLI_EXEC_TIMEOUT=1s to stand in for that.

Self-contained repro, run in an empty directory:

#!/usr/bin/env bash
# Repro: an implicit catalog rebuild inside `show references` runs at source mode under the
# statement timeout; when the timeout fires the cache is not saved, so every later call rebuilds again.
# Needs mxcli.
set -e
cd "$(dirname "$0")"
export MXCLI_LOG_DIR="$PWD/logs"
unset MXCLI_QUIET MXCLI_EXEC_TIMEOUT
P=Repro/Repro.mpr
mxcli new Repro --version 11.12.5 --skip-build > /dev/null

echo "== 1. build a source-mode catalog (explicit refresh, exempt from the timeout)"
mxcli -p $P -c "refresh catalog full source" 2>&1 | grep -E "Building|cached" || true
mxcli -p $P -c "show catalog status" | grep -E "Build mode|Build time|Status"

echo "== 2. touch the .mpr (same content, new mtime: what any save does)"
sleep 2; touch $P

echo "== 3. show references: a full catalog is enough, but it rebuilds at source mode"
mxcli -p $P -c "show references to MyFirstModule.Home_Web" 2>&1 | grep -E "cached|Found"
mxcli -p $P -c "show catalog status" | grep -E "Build mode|Build time|Status"

echo "== 4. same, with the statement timeout below the build time (on a 3k-document app the default 5m does this)"
sleep 2; touch $P
for i in 1 2; do
  MXCLI_EXEC_TIMEOUT=1s mxcli -p $P -c "show references to MyFirstModule.Home_Web" 2>&1 | grep -E "Building|timed out|Found" || true
  mxcli -p $P -c "show catalog status" | grep -E "Build time|Status"
done

Output (progress lines and the PoC banner left out):

== 1. build a source-mode catalog (explicit refresh, exempt from the timeout)
✓ Building blocks: 40
✓ Catalog cached to Repro\.mxcli\catalog.db
Catalog Cache Status
Build mode: source
Build time: 2026-10-07 13:58:39
Status: ✓ Valid
== 2. touch the .mpr (same content, new mtime: what any save does)
== 3. show references: a full catalog is enough, but it rebuilds at source mode
✓ Catalog cached to Repro\.mxcli\catalog.db
Found 2 reference(s)
Catalog Cache Status
Build mode: source
Build time: 2026-10-07 13:58:44
Status: ✓ Valid
== 4. same, with the statement timeout below the build time (on a 3k-document app the default 5m does this)
✓ Building blocks: 40
Error: statement timed out after 1s (raise the limit with MXCLI_EXEC_TIMEOUT, e.g. MXCLI_EXEC_TIMEOUT=30m)
Catalog Cache Status
Build time: 2026-10-07 13:58:44
Status: ✗ Invalid (project file modified)
✓ Building blocks: 40
Error: statement timed out after 1s (raise the limit with MXCLI_EXEC_TIMEOUT, e.g. MXCLI_EXEC_TIMEOUT=30m)
Catalog Cache Status
Build time: 2026-10-07 13:58:44
Status: ✗ Invalid (project file modified)

4. Expected output

• A catalog build that a statement triggers implicitly is not cut off by the statement guard. It is exempt in the same way as refresh catalog (REFRESH CATALOG SOURCE leading to timeout (5mins) #651), or the guard applies only to the statement's own work after ensureCatalog.
• Or: an implicit rebuild for a full-mode consumer builds full, not source. It prints a warning that the source index is now stale, plus the refresh catalog source command to restore it. In this app that turns a call of more than 5 minutes into a call of about 1 minute.
• In any case: if a build is interrupted, the next call should not repeat the same doomed build silently. A hint such as "the last implicit catalog rebuild timed out; run refresh catalog" would already help.

5. Experienced output

Step	Expected	Actual
show references after a save, source-mode cache	full rebuild (~1 min on this app), or source rebuild that completes	source rebuild, stopped by the 5m guard
cache after the timeout	rebuilt	unchanged (Build time stays the same, Invalid (project file modified))
next show references	served from cache	same rebuild, same timeout, every call

Other spellings tried (same app, MXCLI_EXEC_TIMEOUT=1s, stale source cache)

• search 'Home' → Error: statement timed out after 1s (raise the limit with MXCLI_EXEC_TIMEOUT, e.g. MXCLI_EXEC_TIMEOUT=30m)
• show callers of MyFirstModule.Home_Web → same error
• show impact of MyFirstModule.Home_Web → same error
• refresh catalog without MXCLI_EXEC_TIMEOUT → ✓ Catalog cached to Repro\.mxcli\catalog.db (the exemption works for the explicit statement)

6. AI bug report

mxcli diag of the repro run:

  Version:     nightly-20261007-a924d11b7
  Go:          go1.26.6 windows/amd64
  Sessions:    14 (last 7 days)
  Errors:      6 (last 7 days)

Session log of the three show references to MyFirstModule.Home_Web calls (from mxcli diag --bundle):

{"time":"2026-10-07T13:58:42.3786029+02:00","level":"INFO","msg":"session_start","version":"nightly-20261007-a924d11b7","go":"go1.26.6","os":"windows","arch":"amd64","mode":"batch","args":["mxcli","-p","Repro/Repro.mpr","-c","show references to MyFirstModule.Home_Web"],"pid":29476,"parent_pid":""}
{"time":"2026-10-07T13:58:44.3064543+02:00","level":"INFO","msg":"execute","stmt_type":"ShowStmt","stmt_summary":"show REFERENCES MyFirstModule.Home_Web","duration_ms":1845}
{"time":"2026-10-07T13:58:44.3064543+02:00","level":"INFO","msg":"session_end","commands_executed":2,"errors_count":0,"duration_s":1,"pid":29476}
{"time":"2026-10-07T13:58:47.1018248+02:00","level":"INFO","msg":"session_start","version":"nightly-20261007-a924d11b7","go":"go1.26.6","os":"windows","arch":"amd64","mode":"batch","args":["mxcli","-p","Repro/Repro.mpr","-c","show references to MyFirstModule.Home_Web"],"pid":32408,"parent_pid":""}
{"time":"2026-10-07T13:58:48.1969687+02:00","level":"ERROR","msg":"execute_error","stmt_type":"ShowStmt","stmt_summary":"show REFERENCES MyFirstModule.Home_Web","error":"statement timed out after 1s (raise the limit with MXCLI_EXEC_TIMEOUT, e.g. MXCLI_EXEC_TIMEOUT=30m)","duration_ms":1000}
{"time":"2026-10-07T13:58:48.1969687+02:00","level":"INFO","msg":"session_end","commands_executed":2,"errors_count":1,"duration_s":1,"pid":32408}
{"time":"2026-10-07T13:58:48.7481304+02:00","level":"INFO","msg":"session_start","version":"nightly-20261007-a924d11b7","go":"go1.26.6","os":"windows","arch":"amd64","mode":"batch","args":["mxcli","-p","Repro/Repro.mpr","-c","show references to MyFirstModule.Home_Web"],"pid":45844,"parent_pid":""}
{"time":"2026-10-07T13:58:49.8802774+02:00","level":"ERROR","msg":"execute_error","stmt_type":"ShowStmt","stmt_summary":"show REFERENCES MyFirstModule.Home_Web","error":"statement timed out after 1s (raise the limit with MXCLI_EXEC_TIMEOUT, e.g. MXCLI_EXEC_TIMEOUT=30m)","duration_ms":1000}
{"time":"2026-10-07T13:58:49.8802774+02:00","level":"INFO","msg":"session_end","commands_executed":2,"errors_count":1,"duration_s":1,"pid":45844}

The first call takes 1845 ms because it rebuilds and saves the catalog. The next two each spend their whole budget on the same rebuild and end in execute_error. Nothing is saved in between.

Why it matters

An agent or developer saves the project in Studio Pro and then asks "who calls X?". On a large app with a source-mode cache, that question now fails after 5 minutes, and it fails again on every retry. Each run costs 5 minutes and leaves the cache as stale as before. The source mode comes from an earlier, deliberate refresh catalog source and silently decides the cost of every later show references.

Workarounds: run refresh catalog explicitly after each save (it is exempt from the guard). Or set MXCLI_EXEC_TIMEOUT (e.g. 20m). Or delete catalog.db and build full, so implicit rebuilds stay at full.

[github-actions]

Issue Triage

Summary:
The issue describes that implicit catalog rebuilds triggered by show references, search, show callers, and show impact run in source mode under the statement timeout guard, causing the build to be aborted and the cache left stale, so every subsequent call repeats the same failed rebuild.

Checklist of required bug‑report information

Required info	Present?	Notes
mxcli version	✅	nightly-20261007-a924d11b7 (also tested on v0.25.0)
Mendix version	✅	11.12.5
Scenario	✅	Detailed steps with a reproducible script showing when the problem occurs
Expected output	✅	Listed in section 4 (explicit exemption or full‑mode rebuild, timeout not cutting off implicit rebuild)
Experienced output	✅	Section 5 shows actual behavior (timeout, stale cache, repeated failures)
AI bug report (mxcli diag --bundle or session log)	✅	Includes mxcli diag output and full session log for the failing calls

Conclusion:
All required information for a bug report is present. Thank you for providing a clear, reproducible example and thorough diagnostics!

---

Automated triage via OpenRouter — workflow source