Count each runner's simulation time separately (#333)

A model built once and simulated several ways - an FMU handed to
several tools, or a wasm artifact run as a simulation, as FMI 3.0
ME and as CS - wrote the same exectime into every one of its
branch tables, because exectime is the wall clock of the whole
run of the model. The overview therefore gave wasm-jit,
wasm-jit-me and wasm-jit-cs one identical execution time that was
really all three of them added together.

Only the simulation and the verification differ between the
runners; everything up to the build is shared. Each runner now
reports the shared part plus what it alone simulated and
verified. testmodel.py records a simwall beside sim for that
subtraction: sim is what the tool says it spent, which for the
artifact runners is omc's timeSimulation and leaves out the
loading around it, and that overhead would otherwise land in the
shared part and be counted once per runner.

The overview's branch table also gains a simulation time and a
number of verified models, so the two figures that differ between
runners of the same artifact can be read directly:

| Branch | Version | Build time | Execution time | Simulation time | # Simulate | # Verify | # Total |
| --- | --- | --- | --- | --- | --- | --- | --- |

Rows already in the database keep the exectime they were written
with; the new columns are correct for them, since simulate and
finalphase have always been per runner.

Assisted-by: Claude Opus 5 (1M context)

Author: sjoelund

overview.html.tpl

@@ -20,7 +20,7 @@
 </table>
 <h2>Tested branches</h2>
 <table>
-<tr><th>Branch</th><th>Version</th><th>Build time</th><th>Execution time</th><th># Simulate</th><th># Total</th></tr>
+<tr><th>Branch</th><th>Version</th><th>Build time</th><th>Execution time</th><th>Simulation time</th><th># Simulate</th><th># Verify</th><th># Total</th></tr>
 #branches#
 </table>
 #entries#

report.py

@@ -38,7 +38,9 @@
 
 nmodels = {}
 nsimulate = {}
+nverify = {}
 exectime = {}
+simtime = {}
 
 missing_branches = []
 for branch in branches:
@@ -77,7 +79,9 @@
       branch_nmodels += 1
   nmodels[branch] = branch_nmodels
   nsimulate[branch] = 0
+  nverify[branch] = 0
   exectime[branch] = 0.0
+  simtime[branch] = 0.0
 
 entries = ""
 # removing missing branches
@@ -131,6 +135,7 @@ def checkEqual(iterator):
       entries += '<td%s><a%s>%s%s</a></td>' % (' class="warning"' if old_vs and old_vs[i]>vs[i] else (' class="better"' if old_vs and old_vs[i]<vs[i] else ""),' class="dot"' if diff_text else "",vs[i],('<span class="tooltip">%s</span>' % diff_text) if diff_text else "")
     entries += "</tr>"
     nsimulate[branch] += vs[6]
+    nverify[branch] += vs[7]
     if old_vs:
       old_vs = [max(vs[i], old_vs[i]) for i in range(0, len(vs))]
     else:
@@ -144,15 +149,17 @@ def checkEqual(iterator):
     entries += '<tr><td><a href="%s/%s/%s.html">%s</a></td>' % (branch,lib,lib,branch)
     entries += ("<td>%s</td><td>%s</td><td>%s</td><td>%s</td><td>%s</td><td>%s</td><td>%s</td><td>%s</td><td>%s</td></tr>\n" % (friendlyStr(sums[0]),friendlyStr(sums[1]),friendlyStr(sums[2]),friendlyStr(sums[3]),friendlyStr(sums[4]),friendlyStr(sums[5]),friendlyStr(sums[6]),friendlyStr(sums[7]),friendlyStr(sums[8])))
     exectime[branch] += sums[0]
+    simtime[branch] += sums[7]
   entries += "</table>\n"
   # print(sorted(list(libs[lib])))
 
 nummodels = sum(len(l) for l in libs.values())
-branches_lines = [("<tr><td>%s</td><td>%s</td><td>%s</td><td>%s</td><td%s>%d</td><td>%d</td></tr>\n" % (html.escape(branch), html.escape(
+branches_lines = [("<tr><td>%s</td><td>%s</td><td>%s</td><td>%s</td><td>%s</td><td%s>%d</td><td>%d</td><td>%d</td></tr>\n" % (html.escape(branch), html.escape(
   (cursor.execute("SELECT omcversion FROM omcversion WHERE date=? AND branch=?", (max(dates[branch][lib] for lib in libnames),branch)).fetchone() or ["unknown"])[0]
-  ), html.escape(dates_str[branch]), friendlyStr(exectime[branch]),
+  ), html.escape(dates_str[branch]), friendlyStr(exectime[branch]), friendlyStr(simtime[branch]),
   " class=\"warning\"" if nummodels!=nmodels[branch] else "",
   nsimulate[branch],
+  nverify[branch],
   nmodels[branch]
 )) for branch in branches]
 template = open("overview.html.tpl").read()

test.py

@@ -991,6 +991,26 @@ def phaseWithoutSimulator(data):
   """
   return min(data.get("phase") or 0, BUILD_PHASE)
 
+def simulatedTime(simulated):
+  """The wall clock simulating and verifying once cost.
+
+  An older result file has no simwall and only says what the tool spent.
+  """
+  sim = simulated.get("simwall")
+  if sim is None:
+    sim = simulated.get("sim") or 0.0
+  return sim + ((simulated.get("diff") or {}).get("time") or 0.0)
+
+def runnerExecTime(data, simulated):
+  """The wall clock one runner of an FMU or of an artifact cost.
+
+  exectime is the whole run of the model, and all but the simulations is shared
+  by its runners, so each reports the shared part plus only its own simulation.
+  """
+  runners = [data] + list((data.get("simulators") or {}).values())
+  shared_time = (data.get("exectime") or 0.0) - sum(simulatedTime(r) for r in runners)
+  return max(0.0, shared_time) + simulatedTime(simulated)
+
 def resultValues(model, libname, data, simulator=None):
   """One row of a branch table.
 
@@ -1005,7 +1025,7 @@ def resultValues(model, libname, data, simulator=None):
   return (testRunStartTimeAsEpoch,
     libname,
     model,
-    data.get("exectime") or 0.0,
+    runnerExecTime(data, simulated),
     data.get("frontend") or 0.0,
     data.get("backend") or 0.0,
     data.get("simcode") or 0.0,

testmodel.py

@@ -236,6 +236,7 @@ def target(res):
   "templates":None,
   "build":None,
   "sim":None,
+  "simwall":None, # Wall clock; sim is what the tool says it spent
   "simcold":None,
   "diff":None,
   "phase":0,
@@ -779,9 +780,11 @@ def simElapsed():
     else:
       res = checkOutputTimeout("(rm -f %s.pipe ; mkfifo %s.pipe ; head -c 1048576 < %s.pipe >> %s & %s > %s.pipe 2>&1)" % (conf["fileName"],conf["fileName"],conf["fileName"],simFile,cmd,conf["fileName"]), conf["ulimitExe"], conf)
   execstat["sim"] = simElapsed()
+  execstat["simwall"] = monotonic()-start
   execstat["phase"] = 6
 except TimeoutError as e:
   execstat["sim"] = monotonic()-start
+  execstat["simwall"] = execstat["sim"]
   # checkOutputTimeout raises TimeoutError for a command that fails as well as
   # for one that runs out of time, so this covers both.
   if len(runners) > 1:
@@ -917,7 +920,7 @@ def verifyAgainstReference(resFile, prefix, stat):
 # results down with it and leaves the others alone - the first one included,
 # see the TimeoutError handler above.
 for (name, command) in runners[1:]:
-  stat = {"sim": None, "diff": None, "phase": 5}
+  stat = {"sim": None, "simwall": None, "diff": None, "phase": 5}
   simulators[name] = stat
   simFileOther = os.path.abspath("../files/%s_%s.sim" % (conf["fileName"], name)).replace('\\','/')
   other = resultFile(name)
@@ -926,16 +929,19 @@ def verifyAgainstReference(resFile, prefix, stat):
     if useArtifact:
       res = simulateArtifact(name, command, other, simFileOther)
       stat["sim"] = res.get("timeSimulation") or (monotonic()-start)
+      stat["simwall"] = monotonic()-start
       if not res.get("resultFile"):
         writeResult()
         continue
     else:
       simulateFmu(name, command, other, simFileOther)
       stat["sim"] = monotonic()-start
+      stat["simwall"] = stat["sim"]
     stat["phase"] = 6
     verifyAgainstReference(other, artifactPrefix(name) + ".diff", stat)
   except TimeoutError as e:
     stat["sim"] = monotonic()-start
+    stat["simwall"] = stat["sim"]
     with open(errFile, 'a+') as fp:
       fp.write("%s timed out simulating the %s\n" % (name, "artifact" if useArtifact else "FMU"))
   writeResult()