Record what a command killed by the watchdog cost

[adrpo]

A model whose command runs out of time reports nothing for the phase it was in. The time only survives in exectime, and no report shows exectime per phase, so it vanishes.

In the master run of 2026-08-12 that is 15 models and 1.34 hours. Three of them are BuildingSystems models that spend the full 660 second ulimitOmc budget inside translateModel and are recorded like this:

model                                                total  parse  fe  be  sc  tpl  comp  finalphase
BuildingSystems.Buildings.Zones.Examples.SingleZo...   666      3   0   0   0    0     0           0

Eleven minutes, of which three seconds are accounted for.

Why

The caller does try to account for it:

except TimeoutError as e:
  execstat["frontend"]=monotonic()-start

That handler never runs. sendExpressionTimeout kills the command and calls writeResultAndExit itself, from inside, before raising anything:

with open(errFile, 'a+') as fp:
  fp.write("Aborted the command.\n")
writeResultAndExit(0, True, omc, omc_new)

So the process is gone before the exception reaches the caller, and the results written are whatever execstat held when the command started. The same applies to the path where omc dies mid-command.

The change

Recording it where the results are written covers every way out, rather than the one path that remembered to. A phase says when it started, writeResult charges it if it never reported a time of its own, and a phase that ends normally still reports exactly what it did before:

def writeResult():
  if runningPhase is not None:
    (key, started) = runningPhase
    # Only if the phase did not get to report its own time.
    if not execstat.get(key):
      execstat[key] = monotonic() - started

Which phase a killed command belongs to cannot be known — omc's timers die with it — so it is charged to what the command itself is: building an FMU to the build, simulating to the simulation, translating to the front end. That last one is also the phase such a model is reported as having failed in, so the row stays self-consistent.

Testing

Modelica.Fluid.Examples.HeatExchanger.HeatExchangerSimulation with ulimitOmc=1, which the watchdog kills (Thread is still alive. / Aborted the command.):

before   {'parsing': 1.73}
after    {'parsing': 1.65, 'frontend': 3.01}

Modelica.Blocks.Examples.PID_Controller, which succeeds, is unchanged:

before   {'parsing': 1.69, 'frontend': 0.02, 'backend': 0.06, 'simcode': 0.01, 'templates': 0.09, 'build': 2.08, 'sim': 0.15, 'phase': 6}
after    {'parsing': 1.76, 'frontend': 0.02, 'backend': 0.05, 'simcode': 0.01, 'templates': 0.09, 'build': 1.99, 'sim': 0.17, 'phase': 6}

Both run against the real testmodel.py of this branch and of origin/master, on the same configuration.

Scope

This is the part of #308 that is a genuine defect. The rest of that issue's description was wrong and is corrected in a comment there: ordinary failures do record the phase they failed in — 851 of 867 front end failures and all 301 back end failures carry a time — and the remaining unattributed hours are about 0.7 s per model of process startup and teardown, which belongs to no phase because it is not one.

Part of #308.

---

Generated by Claude Code.