Skip to content

exec.sh: ~69 s of bookkeeping plus a 165 s deploy-build gate for a 1 s model write (Windows profile) #585

Closed

Description

@mkr87

Per-command profile of one bin/exec.sh run on Windows (Git Bash 5.3 / Cygwin), toolkit c28fc0d, mxcli v0.28.0, Mendix 11.12.6. The run was an idempotent re-run of an already-applied 5-statement script: the model write itself took 1.1 s, and the whole run took 234 s.

How measured: export PS4='+${EPOCHREALTIME} ${BASH_SOURCE##*/}:${LINENO} ' SHELLOPTS; bash -x bin/exec.sh <script>. Each line is charged the gap until the next traced line (5,137 lines).

Where the time went

Phase Time Main cost
guards 8.9 s exec-approval, mdl-scan, row-groups check 2.6 s
check 9.0 s mxcli check via tee 3.5 s, script-owners check 2.4 s, mxtk_model_version 1.4 s
snapshot 7.2 s cp -r mprcontents 2.7 s, rm -rf old snapshot 0.8 s
baseline 7.2 s model-stamp.sh check -q --clean 5.5 s
exec 1.2 s the actual write
gate 165.8 s one mxbuild --target=deploy: 165 s
lint 6.5 s lint-gate.sh 5.9 s
score 5.7 s metrics-ledger score 5.5 s
after verdict 23.0 s build-plan-status --refresh 8.3 s, metrics-ledger exec 3.0 s, script-owners record 1.7 s

Totals: 165 s mxbuild, ~34 s before the write, ~35 s after the gate. About 69 s is toolkit bookkeeping for a 1 s write.

On this machine (corporate Windows 11, Defender real-time protection on): a $(...) subshell costs ~58 ms, an external program ~86 ms, a builtin ~0. The 4,972 traced lines that took under 0.5 s add up to 24.9 s, which is the per-fork cost spread across the helpers.

Findings / suggestions, by time saved

  1. The per-exec gate is a full deploy build. It took 165 s in this run, 18-20 s in warm runs earlier the same day, and ~156 s cold. mx check on the same model takes 12 s and reports the same 0 errors. Suggest mx check as the per-exec gate, with the deploy build (javac etc.) only when Java/JS actions changed, at module close, or before commit. At minimum, print "full deploy build, can take 2-3 min" so the run doesn't look hung.
  2. 23 s of work after the verdict is already known. build-plan-status --refresh (8.3 s), the ledger row and script-owners record could run in the background or be deferred to commit/close-task.
  3. lint (5.9 s) and score (5.5 s) are two separate passes over the same model. One pass could produce both.
  4. Repeated model and stamp reads before the write. model-stamp check 5.5 s, mxtk_model_version 1.4 s (still called when MXBUILD_PATH is set), row-groups 2.6 s, script-owners 2.4 s. Memoize the model version and stamp per run (keyed on the .mpr mtime), and fold the two script-owners calls into one.
  5. Snapshot copies the whole mprcontents/ (2.7 s, and growing with the model). Consider git stash/a commit-based snapshot, or hardlinks, when the tree is clean.
  6. Fork-heavy helpers. On Windows every $(...), | sed, | head, dirname or date costs 60-90 ms. Prefer builtins (${var%/*}, printf -v, $EPOCHSECONDS) on the hot path.
  7. Ship this profiler. An MXTK_PROFILE=1 switch that sets the PS4 above and prints the per-phase table would let users file numbers like these without digging.

Complements the earlier field report "exec.sh performance on Windows (Git Bash): where the time went" (setting MXBUILD_PATH saves ~6 s/run; spawn cost is ~94 ms; 4 of 9 runs blocked on an uncommitted model).

Activity

  1. MendixMau commented on Oct 28, 2026

    @MendixMau
    Owner

    Triage: DISCUSS track. Performance, plus a process path (the per-exec gate) in every entry mode that runs exec.sh (migration, requirements-driven, greenfield, change an existing app). Code paths verified; timings UNVERIFIED (Windows profile not reproduced here).

    Problem:

    • The per-exec gate is a full deploy build: project-bin/exec.sh:1850 → mxtk_mxbuild_error_count, which runs mxbuild --target=deploy (project-bin/_common.sh:910). Cold, that took 165 s against a 1.1 s write.
    • Before the write, the model is read several times. mxtk_ensure_mxbuild calls mxtk_model_version even when MXBUILD_PATH is set (_common.sh:1050). Then model-stamp.sh check (exec.sh:1567), row-groups.sh check (exec.sh:618) and script-owners.sh check (exec.sh:1230) each read it again.
    • Work after the verdict: build-plan-status --refresh runs synchronously (exec.sh:2234).
    • There is no profiler: no MXTK_PROFILE anywhere on master.
    • Who hits it: every Windows/Git Bash user, on every exec. About 69 s of bookkeeping plus the gate.

    Value: High. This is the inner build loop. Your numbers put model work under 5% of each run.

    Options:

    1. Profiler first. MXTK_PROFILE=1 prints a per-phase table and counts spawns, for both exec.sh and gate-check.sh. This is the same switch as Stage 3 (Architecture & Design) takes ~1h50m wall time on a 1-module, 7-page demo slice; gate-check + closeout alone ~12 min #583 option 1: one instrument, two reports. No path changes, near-zero cost when off. Small.

    2. Cheap wins, no process change.

      • Work out the model version and mxbuild path once per run, and skip the version lookup when MXBUILD_PATH is set.
      • Merge the two script-owners calls into one.
      • Print "full deploy build, can take 2-3 min" before the gate.
      • Run the work after the verdict in the background.

      Estimated saving: about 15-25 s per run on Windows. Medium. The risk is in the background step: a ledger or status row could still be being written when the next exec starts.

    3. Lighter per-exec gate: run mx check (about 12 s) on every exec. Run the deploy build only when Java/JS actions changed, at module close, or before commit. Saves around 150 s cold and 6-8 s warm. This changes the process: a javac-level error is caught later, at module close instead of at the exec that caused it. Large, and it needs a field run on both layouts.

    Recommendation: 1 now, then 2. Decide on 3 once the profiler has numbers from at least one macOS project and one Windows project. 3 is the biggest saving, but it moves when build errors are caught.

    Decision needed from you: build the shared profiler (option 1, which also settles #583), or go straight to option 2 or 3? Reply "go option N" to build it.


    Generated by Claude Code

  2. MendixMau commented on Nov 3, 2026

    @MendixMau
    Owner

    Thanks @mkr87 — closing as fixed: the per-exec bookkeeping was trimmed (#596/#597) and Gate mode: check now gates each exec with mx check instead of a full deploy build; the full build runs at the module boundary (bin/module-close.sh). Please reopen with a fresh timing if you still see it on current master.


    Generated by Claude Code

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions