A model that fails records no time for the phase it failed in

[adrpo]

A model that fails in a phase records no time for that phase, so the work it did disappears from every report. Only exectime still counts it, and nothing displays exectime per phase.

Three models of BuildingSystems in the last master run:

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

Eleven minutes each, reported as zero seconds everywhere. The .err file says what really happened - and it is not an error, it is a timeout:

translateModel(BuildingSystems.Buildings.Zones.Examples.SingleZoneThermal3x3x3, ...) [Timeout 660]
Thread is still alive.
Aborted the command.
[Calling os._exit(0), Time elapsed: 665.8362961709499]

660 seconds is ulimitOmc, the budget for translating a model. They spend all of it, are killed, and are recorded as having spent nothing.

Why

testmodel.py reads the timers after translateModel and only assigns a phase its time when the following timer has a value:

if backend != -1:
  execstat["frontend"] = frontend - backend
  if templates != -1:
    execstat["backend"] = backend - simcode
    ...
else:
  execstat["phase"] = 0
  execstat["frontend"] = frontend

The last branch does set frontend, but frontend is timerTock(RT_CLOCK_FRONTEND), which is -1 when the front end never finished - so a model that dies there stores -1 or 0, not the eleven minutes it spent. The same holds one level down for the back end.

How much

Summed over the last master run, 19566 models, 82.5 hours of exectime:

	hours
accounted for by the phase columns	77.6
attributed to no phase at all	4.9

and by how far the model got:

finalphase	models	hours	of which unattributed
7 Verify	10016	34.9	2.0
0 Failed	881	5.0	1.5
6 Simulate	7605	28.4	1.3
1 FrontEnd	301	1.3	0.1
5 Compile	588	12.1	0.1

So 881 models cost five hours of every run and produce nothing, and a third of that time is not visible in any phase. The rest of the unattributed time is process start-up, loading the result file and so on, spread thinly over the models that succeed.

Those 881 are two different things, and the reports cannot tell them apart either:

	models	hours
fail quickly	878	4.5
time out in translateModel (>600 s)	3	0.6

The 878 average eighteen seconds each, most of which is loading the library before failing - they are cheap individually and add up only because there are so many. The three are BuildingSystems models that consume the full 660 second budget every single run.

What to do

Record what a phase cost even when it fails. The wall clock is available - testmodel.py already measures exectime around the whole run of a model - so a failing phase can be charged with the time between entering it and giving up, rather than with nothing.

The .err file of a failing model already holds the diagnosis, and it is published beside the results, so a report that says "these models fail and cost this much" can link straight to it. Today one has to know the model failed, find its page, and open the file.

Worth deciding as part of it:

• whether a failed phase's time belongs in the same column as a successful one, or in a column of its own. The same column is more useful for "where does the run go"; a separate one keeps "how long does the front end take when it works" clean.
• whether the reports should show it. A row saying 881 models spent 5 hours failing in the front end is worth more than the same 5 hours spread invisibly over exectime.

Why it matters

It came up while looking at where a master run spends its 82.5 hours, and the answer was distorted by exactly this. Anyone doing that investigation reaches for the phase columns, and they quietly under-report the models that fail - which are the models most likely to be worth looking at.

---

Generated by Claude Code.

[adrpo]

Correcting this: the diagnosis in the description is wrong. A model that fails in a phase does record that phase's time, in the two cases the issue named. Measured on the master run of 2026-08-12:

final phase	models	with a time for the phase they failed in	recorded
0 — front end	867	851	1.22 h
1 — back end	301	301	0.82 h

The timerTock values are elapsed times of clocks that are still running, so a phase that never finished still reports how long it had been going. The code reads them correctly and the earlier reading of it was wrong.

The hours in the tables are real, though. Where the time actually goes:

1. Models killed by the watchdog record nothing — 15 models, 1.34 h. They are the 15 of the 867 in the table above with no front end time, and they are what the three BuildingSystems models in the description really are. The caller does try to account for it:

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

but that handler never runs, because sendExpressionTimeout kills the command and calls writeResultAndExit itself, from inside, before raising. The process is gone before the caller sees the exception, so the results written are whatever execstat held when the command started. Same for the path where omc dies mid-command.

2. The remaining ~3.8 h is per-model overhead, spread thin. Starting python and omc, reading the configuration, writing the files, tearing down: about 0.7 s per model over 19650 models. It is 5–6% on a model that succeeds and proportionally much larger on one that fails quickly, which is what made failures look mis-accounted. It belongs to no phase because it genuinely is not one.

So there is one bug here, not the one described, and it is worth fixing because a timed-out model is exactly the kind you want to find: it costs the most and produces nothing.

The open question in the description — whether a failed phase's time belongs in the same column as a successful one — is settled by this: it already goes in the same column, and has done all along.

---

Generated by Claude Code.

[adrpo]

Closing this: the one real bug behind it is fixed, and the rest turned out not to be a bug.

The description's diagnosis — that a model failing in a phase records no time for that
phase — is wrong, as corrected above.
timerTock reports the elapsed time of a clock that is still running, so a phase that
never finished still reports how long it had been going; 851 of 867 front-end failures
and all 301 back-end failures in the master run of 2026-08-12 did record their time.

What the three BuildingSystems models in the description actually were is models killed
by the watchdog, and those genuinely recorded nothing: sendExpressionTimeout called
writeResultAndExit from inside the timeout path, so the process was gone before the
caller's except TimeoutError handler could attribute the elapsed time. 15 models,
1.34 hours in that run. Fixed by #310.

The ~3.8 hours still attributed to no phase is per-model overhead — starting python and
omc, reading the configuration, writing the files, tearing down — about 0.7 s across
19650 models. It belongs to no phase because it is not one.

---

generated by Claude Code