From 3a81b90a2551941925fd1df629c8841c7555a981 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Martin=20Sj=C3=B6lund?= Date: Sun, 30 Aug 2026 09:38:18 +0200 Subject: [PATCH] Cut the simulation timeout from 8 minutes to 4 A simulation was killed after ulimitExe seconds, 8 minutes by default. On master, which runs on the slower test machines, 99.5% of the models that simulate at all are done inside 105 seconds, so the default mostly bought the hanging models time to hang in: about 49 models per master run spent more than two minutes each and failed anyway. One number per library cannot be tightened much on its own, because it has to cover the slowest model of the library and so hands every other model the same licence - Buildings needs 640s for 18 of its 1786 models. A model that has earned longer therefore names itself in ulimitExeModels, and its library keeps the short default. Sizing the default from a held-out month, replaying limits derived from 100 master runs against the next 100: | default | named models | spurious timeouts/run | simulation saved | | ------- | ------------ | --------------------- | ---------------- | | 120s | 98 | 1.65 | 4.6 h/run | | 180s | 55 | 0.99 | 3.7 h/run | | 240s | 40 | 0.48 | 2.9 h/run | | 300s | 25 | 0.13 | 2.0 h/run | Consecutive master runs already differ in some 50 model statuses, 13 of them simulation regressions, so 240s adds about 4% to that where 120s would add 13%. The margin on top of a model's observed maximum matters far less: 1.25 and 3.0 differ by 0.01 h/run and not at all in the breach count, because what overruns is models nothing named. What is committed here saves 2.85 h of simulation per master run, all of it on runs that fail anyway, and drops what a run is licensed to spend simulating from 2822 h to 1324 h. Sizing from master costs the other jobs almost nothing - no newly failing models on v1.26, v1.27 or master-fmi and 4 to 12 on cvode, gbode, cpp and fmi-fmpy - bar newInst-newBackend at 52, where the new backend really is that much slower on OpenIPSL and IBPSA. update-ulimit-exe.py derives the numbers from the results database and writes them back, editing the files as text so that setting one does not reformat the other ninety-five entries, and checking that the result parses to what it was meant to say before writing it. job_claim is now created on the first claim rather than on connect, so the scripts that only read - the reports and this one - no longer need a database user that may write. The watchdogs meant to cut a hung model short cannot kill anything on Windows, which is why they never did: signal.SIGKILL and os.killpg do not exist there, and the AttributeError that raises is not the OSError the kill loops catch. The escape path threw while the worker thread sat in a ZMQ receive that never returns, and the interpreter then waited for that non-daemon thread forever, so a hung model was ended by test.py's outer timeout, 2*ulimitOmc + ulimitExe + 25, rather than by its own - eleven minutes later and with nothing written down. The GitHub sanity check has been hitting this on windows-latest about every fifth run since 7 August, spending 1900 seconds where a passing run spends 120. The kill loops are now one helper per script, the worker threads are daemons, and Windows signals the whole process tree, since the command runs under a shell of its own there and killing the shell leaves the command running. A model that hangs still fails; this only makes it fail at its own timeout, and leave the log that says where it hung. Assisted-by: Claude Opus 5 --- README.md | 37 ++++- configs/conf.json | 89 ++++++++++-- configs/heavy_tests.json | 39 +++++- library.html.tpl | 2 +- resultsdb.py | 18 ++- shared.py | 25 +++- test.py | 40 ++++-- testmodel.py | 53 +++----- update-ulimit-exe.py | 284 +++++++++++++++++++++++++++++++++++++++ 9 files changed, 519 insertions(+), 68 deletions(-) create mode 100755 update-ulimit-exe.py diff --git a/README.md b/README.md index 7709558..a027a0f 100644 --- a/README.md +++ b/README.md @@ -125,7 +125,10 @@ different OpenModelica versions, according to the conditions of the "defaultTolerance": 1e-6, // tolerance for tests if not specified by the model, defaults to 1e-6 "defaultNumberOfIntervals": 2500, // number of intervals for tests if not specified by the model, defaults to 2500 "ulimitOmc":800, // specify a max timeout for a model build - "ulimitExe":300, // specify a max timeout for a model simulation + "ulimitExe":300, // specify a max timeout for a model simulation, defaults to 240 + "ulimitExeModels":{ // the models of this library that are allowed longer, see Simulation timeouts + "MyModelicaLibrary.Examples.SomethingBig":600 + }, "ulimitMemory":62000000, // specify a max for the virtual memory of the running process when building a model "procOMC":0, // [if procOMC = 0 use max procs, use procOMC = 1 if not defined, else use the given value] how many CPU cores should be used to run omc (load Modelica libraries in parallel and generate the C code in parallel) "procCCompile":0, // [if procCCompile = 0 use max procs, use procCCompile = 1 if not defined, else use the given value] how many CPU cores should be used to compile the generated code @@ -201,6 +204,38 @@ Options: `procCCompile` above for more insight into individual test parallelization. +### Simulation timeouts + +A simulation is killed after `ulimitExe` seconds, 240 by default - 99.5% of the +models that simulate at all are done inside 105 on master, which runs on the +slower test machines. One number per library would have to cover its slowest +model, giving every other model of the library the same licence to hang, so a +library keeps the short timeout and names the forty-odd models that earned more: + +```json +"ulimitExeModels":{ + "Buildings.DHC.Examples.Combined.SeriesVariableFlow":810 +} +``` + +[update-ulimit-exe.py](./update-ulimit-exe.py) writes those lists from the +results, so they stay measurements rather than guesses. The first line says what +would change, the second changes it: + +```bash +./update-ulimit-exe.py --db postgresql://om@openmodelica.org/omdb configs/conf.json +./update-ulimit-exe.py --db postgresql://om@openmodelica.org/omdb --write configs/*.json +``` + +Both lines only read the database - `--write` writes the configuration files - +so a read-only user is enough for either. + +Every model is allowed `--factor` times the longest it has taken over `--runs` +runs of `--branch`. A model that only ever ran into the timeout, and a library +the database has never heard of, are reported rather than guessed at. Run it +after a machine is replaced, after a change that moves the timings, or when the +reports start showing models killed by the timeout. + ### Testing FMI with several simulators Building an FMU costs far more than simulating it: on the twelve models of diff --git a/configs/conf.json b/configs/conf.json index 53fb3b2..7354c25 100644 --- a/configs/conf.json +++ b/configs/conf.json @@ -2,6 +2,9 @@ { "library":"Modelica", "libraryVersion":"trunk", + "ulimitExeModels":{ + "Modelica.Electrical.PowerConverters.Examples.ACAC.SoftStarter":510 + }, "referenceFileExtension":"csv", "referenceFileNameDelimiter":"/", "referenceFileNameExtraName":"$ClassName", @@ -12,6 +15,9 @@ "library":"Modelica", "libraryVersion":"4.1.0", "libraryVersionExactMatch":true, + "ulimitExeModels":{ + "Modelica.Electrical.PowerConverters.Examples.ACAC.SoftStarter":510 + }, "referenceFileExtension":"csv", "referenceFileNameDelimiter":"/", "referenceFileNameExtraName":"$ClassName", @@ -22,6 +28,9 @@ "library":"Modelica", "libraryVersion":"4.0.0", "libraryVersionExactMatch":true, + "ulimitExeModels":{ + "Modelica.Electrical.PowerConverters.Examples.ACAC.SoftStarter":510 + }, "referenceFileExtension":"csv", "referenceFileNameDelimiter":"/", "referenceFileNameExtraName":"$ClassName", @@ -174,7 +183,12 @@ "libraryVersion":"maint.11.x", "libraryVersionNameForTests":"11", "ulimitOmc":300, - "ulimitExe":400, + "ulimitExeModels":{ + "Buildings.Examples.DualFanDualDuct.ClosedLoop":360, + "Buildings.ThermalZones.EnergyPlus_9_6_0.Examples.SmallOffice.Guideline36Spring":420, + "Buildings.ThermalZones.EnergyPlus_9_6_0.Examples.SmallOffice.Guideline36Summer":420, + "Buildings.ThermalZones.EnergyPlus_9_6_0.Examples.SmallOffice.Guideline36Winter":510 + }, "runOnceBeforeTesting":[["$resourceLocation/src/ThermalZones/install.py", "--binaries-for-os-only"]], "referenceFileExtension":"csv", "referenceFileNameDelimiter":"_", @@ -187,7 +201,12 @@ "libraryVersion":"maint.12.x", "libraryVersionNameForTests":"12", "ulimitOmc":300, - "ulimitExe":400, + "ulimitExeModels":{ + "Buildings.Examples.DualFanDualDuct.ClosedLoop":390, + "Buildings.Fluid.Geothermal.ZonedBorefields.Examples.SeriesConnectedZones":390, + "Buildings.ThermalZones.EnergyPlus_24_2_0.Examples.SmallOffice.Guideline36Spring":450, + "Buildings.ThermalZones.EnergyPlus_24_2_0.Examples.SmallOffice.Guideline36Summer":420 + }, "runOnceBeforeTesting":[["$resourceLocation/src/ThermalZones/install.py", "--binaries-for-os-only"]], "referenceFileExtension":"csv", "referenceFileNameDelimiter":"_", @@ -200,7 +219,16 @@ "libraryVersion":"master", "libraryVersionNameForTests":"latest", "ulimitOmc":300, - "ulimitExe":800, + "ulimitExeModels":{ + "Buildings.DHC.Examples.Combined.SeriesConstantFlow":780, + "Buildings.DHC.Examples.Combined.SeriesVariableFlow":810, + "Buildings.Examples.DualFanDualDuct.ClosedLoop":390, + "Buildings.Examples.VAVReheat.Guideline36":330, + "Buildings.Fluid.Geothermal.ZonedBorefields.Examples.SeriesConnectedZones":360, + "Buildings.ThermalZones.EnergyPlus_24_2_0.Examples.SmallOffice.Guideline36Spring":450, + "Buildings.ThermalZones.EnergyPlus_24_2_0.Examples.SmallOffice.Guideline36Summer":420, + "Buildings.ThermalZones.EnergyPlus_24_2_0.Examples.SmallOffice.Guideline36Winter":600 + }, "runOnceBeforeTesting":[["$resourceLocation/src/ThermalZones/install.py", "--binaries-for-os-only"]], "referenceFileExtension":"csv", "referenceFileNameDelimiter":"_", @@ -209,10 +237,18 @@ { "library":"BuildingSystems", "libraryVersion":"master", - "libraryVersionNameForTests":"" + "libraryVersionNameForTests":"", + "ulimitExeModels":{ + "BuildingSystems.Applications.AirConditioningSystems.PhotovoltaicCoolingSystem":450, + "BuildingSystems.Applications.HeatingSystems.SolarHeatingSystem":600, + "BuildingSystems.Buildings.Geometries.Viewfactors.Examples.RectangularCuboidSurfaces":510 + } }, { "library":"BuildSysPro", + "ulimitExeModels":{ + "BuildSysPro.Systems.HVAC.Emission.Examples.MozartJoulePIControlled":330 + }, "_comment":"IncludeDirectory says modelica://BuildSysPro/Resources/C-Sources, which does not exist; the IBPSA C sources are in IBPSA/Resources/C-Sources (Resources/IBPSA/C-Sources in 3.5.0 and older). Some of them call str*/malloc/ModelicaError without including the header", "extraCustomCommands":["setCFlags(getCFlags() + \" -include string.h -include stdlib.h -include ModelicaUtilities.h \\\"-I$libraryLocation/IBPSA/Resources/C-Sources\\\" \\\"-I$libraryLocation/Resources/IBPSA/C-Sources\\\"\")"] }, @@ -238,7 +274,6 @@ { "library":"ClaRa", "ulimitOmc":800, - "ulimitExe":800, "referenceFileExtension":"mat", "referenceFileNameDelimiter":".", "referenceFiles":{ @@ -251,7 +286,6 @@ { "library":"ClaRa", "ulimitOmc":800, - "ulimitExe":800, "libraryVersion":"main", "libraryVersionNameForTests":"dev", "referenceFileExtension":"mat", @@ -275,6 +309,9 @@ }, { "library":"Dynawo", + "ulimitExeModels":{ + "Dynawo.Examples.RVS.TestCases.TestB.TestBNoSvcNoLoadReset":330 + }, "extraCustomCommands":["setCommandLineOptions(\"--allowNonStandardModelica=implicitParameterStartAttribute,illegalConditionalContext\");"] }, { @@ -425,7 +462,11 @@ "library":"PhotoVoltaics" }, { - "library":"PhotoVoltaics_TGM" + "library":"PhotoVoltaics_TGM", + "ulimitExeModels":{ + "PhotoVoltaics_TGM.TGM_Comax_Analytical_2016":480, + "PhotoVoltaics_TGM.TGM_Trina_Analytical_2016":510 + } }, { "library":"PNlib", @@ -468,7 +509,9 @@ "libraryVersion":"master", "libraryVersionNameForTests":"", "ulimitOmc":300, - "ulimitExe":300, + "ulimitExeModels":{ + "ScalableTestSuite.Thermal.DistrictHeating.ScaledExperiments.HeatingSystem_N_80":390 + }, "ulimitMemory":12582912, "optlevel":"-Os -march=native", "referenceFileExtension":"mat", @@ -484,7 +527,9 @@ "libraryVersion":"master", "libraryVersionNameForTests":"noopt", "ulimitOmc":300, - "ulimitExe":300, + "ulimitExeModels":{ + "ScalableTestSuite.Thermal.Advection.ScaledExperiments.SteamPipe_N_1280":330 + }, "ulimitMemory":12582912, "optlevel":"-O0", "referenceFileExtension":"mat", @@ -528,7 +573,11 @@ "library":"ThermofluidStream", "libraryVersion":"main", "libraryVersionNameForTests":"dev", - "ulimitExe":1200, + "ulimitExeModels":{ + "ThermofluidStream.Boundaries.Tests.VolumesDirectCoupling":1350, + "ThermofluidStream.Examples.ReverseHeatPump":390, + "ThermofluidStream.Undirected.Boundaries.Tests.VolumesDirectCoupling":420 + }, "referenceFileExtension":"mat", "referenceFileNameDelimiter":".", "referenceFinalDot":"_ref.", @@ -537,7 +586,11 @@ }, { "library":"ThermofluidStream", - "ulimitExe":1200, + "ulimitExeModels":{ + "ThermofluidStream.Boundaries.Tests.VolumesDirectCoupling":1320, + "ThermofluidStream.Examples.ReverseHeatPump":690, + "ThermofluidStream.Undirected.Boundaries.Tests.VolumesDirectCoupling":420 + }, "referenceFileExtension":"mat", "referenceFileNameDelimiter":".", "referenceFinalDot":"_ref.", @@ -567,17 +620,29 @@ }, { "library":"ThermoPower", + "ulimitExeModels":{ + "ThermoPower.Test.DistributedParameterComponents.TestFlow1D2phChen_hf":390, + "ThermoPower.Test.DistributedParameterComponents.TestWaterFlow1DFEM_F":390 + }, "optlevel":"-Os -march=native" }, { "library":"ThermoPower", "libraryVersion":"4.0.0-dev", + "ulimitExeModels":{ + "ThermoPower.Test.DistributedParameterComponents.TestWaterFlow1DFEM_F":390, + "ThermoPower.Test.DistributedParameterComponents.TestWaterFlow1DFEMnm_F":570 + }, "optlevel":"-Os -march=native" }, { "library":"ThermoSysPro", "libraryVersion":"master", - "libraryVersionNameForTests":"" + "libraryVersionNameForTests":"", + "ulimitExeModels":{ + "ThermoSysPro.Examples.SimpleExamples.TestCentrifugalPump7":570, + "ThermoSysPro.Fluid.Examples.SimpleExamples.TestDynamicWaterHeating":540 + } }, { "library":"TransiEnt", diff --git a/configs/heavy_tests.json b/configs/heavy_tests.json index 327e786..7497d0f 100644 --- a/configs/heavy_tests.json +++ b/configs/heavy_tests.json @@ -4,7 +4,12 @@ "libraryVersion":"master", "libraryVersionNameForTests":"OB", "ulimitOmc":400, - "ulimitExe":300, + "ulimitExeModels":{ + "ScalableTestSuite.Electrical.DistributionSystemAC.ScaledExperiments.DistributionSystemLinearIndividual_N_56_M_56":720, + "ScalableTestSuite.Electrical.DistributionSystemAC.ScaledExperiments.DistributionSystemLinear_N_56_M_56":390, + "ScalableTestSuite.Mechanical.FlexibleBeam.ScaledExperiments.FlexibleBeamModelica_N_64":480, + "ScalableTestSuite.Thermal.DistrictHeating.ScaledExperiments.HeatingSystem_N_80":480 + }, "ulimitMemory":62914560, "procOMC":0, "procCCompile":0, @@ -22,7 +27,15 @@ "libraryVersion":"master", "libraryVersionNameForTests":"NB", "ulimitOmc":400, - "ulimitExe":300, + "ulimitExeModels":{ + "ScalableTestSuite.Elementary.ParameterArrays.ScaledExperiments.Table_N_200_M_200":360, + "ScalableTestSuite.Mechanical.HarmonicOscillator.ScaledExperiments.HarmonicOscillatorNetwork_N_320":390, + "ScalableTestSuite.Power.ConceptualPowerSystem.ScaledExperiments.PowerSystemStepLoad_N_64_M_16":510, + "ScalableTestSuite.Power.ConceptualPowerSystem.ScaledExperiments.PowerSystemStepLoad_N_64_M_4":390, + "ScalableTestSuite.Power.ConceptualPowerSystem.ScaledExperiments.PowerSystemStepLoad_N_64_M_8":450, + "ScalableTestSuite.Thermal.Advection.ScaledExperiments.SimpleAdvection_N_3200":390, + "ScalableTestSuite.Thermal.HeatExchanger.ScaledExperiments.CounterCurrentHeatExchangerEquations_N_1280":330 + }, "ulimitMemory":62914560, "procOMC":0, "procCCompile":0, @@ -41,7 +54,26 @@ "libraryVersion":"master", "libraryVersionNameForTests":"NB", "ulimitOmc":400, - "ulimitExe":400, + "ulimitExeModels":{ + "LargeTestSuite.Electrical.TransmissionLine.TransmissionLineModelica_N_10240":840, + "LargeTestSuite.Electrical.TransmissionLine.TransmissionLineModelica_N_2560":480, + "LargeTestSuite.Elementary.SimpleODE.CascadedFirstOrder_N_102400":900, + "LargeTestSuite.Elementary.SimpleODE.CascadedFirstOrder_N_204800":690, + "LargeTestSuite.Elementary.SimpleODE.CascadedFirstOrder_N_409600":990, + "LargeTestSuite.Elementary.SimpleODE.CascadedFirstOrder_N_51200":330, + "LargeTestSuite.Mechanical.HarmonicOscillator.HarmonicOscillator_N_1638400":570, + "LargeTestSuite.Mechanical.HarmonicOscillator.HarmonicOscillator_N_819200":510, + "LargeTestSuite.Thermal.Advection.SimpleAdvection_N_12800":900, + "LargeTestSuite.Thermal.HeatConduction.OneDHeatTransferTI_FD_N_1310720":360, + "LargeTestSuite.Thermal.HeatConduction.OneDHeatTransferTT_FD_N_1310720":360, + "LargeTestSuite.Thermal.HeatExchanger.CocurrentHeatExchangerEquations_N_1280":420, + "LargeTestSuite.Thermal.HeatExchanger.CocurrentHeatExchangerEquations_N_2560":420, + "LargeTestSuite.Thermal.HeatExchanger.CocurrentHeatExchangerEquations_N_5120":390, + "LargeTestSuite.Thermal.HeatExchanger.CocurrentHeatExchangerEquations_N_81920":660, + "LargeTestSuite.Thermal.HeatExchanger.CounterCurrentHeatExchangerEquations_N_1280":330, + "LargeTestSuite.Thermal.HeatExchanger.CounterCurrentHeatExchangerEquations_N_2560":450, + "LargeTestSuite.Thermal.HeatExchanger.CounterCurrentHeatExchangerEquations_N_81920":660 + }, "ulimitMemory":62914560, "procOMC":0, "procCCompile":0, @@ -54,7 +86,6 @@ "libraryVersionNameForTests":"NB_SymbolicJacobian", "ignoreModelPrefix":"ScalableTestGrids.Models.Type1Large", "ulimitOmc":800, - "ulimitExe":300, "ulimitMemory":62000000, "procOMC":0, "procCCompile":0, diff --git a/library.html.tpl b/library.html.tpl index 2cc608e..6d17218 100644 --- a/library.html.tpl +++ b/library.html.tpl @@ -42,7 +42,7 @@ OpenModelicaLibraryTesting Changes
#metadata#

BuildModel time limit: #ulimitOmc#s
-Simulation time limit: #ulimitExe#s
+Simulation time limit: #ulimitExe#s
#ulimitExeModels# Default tolerance: #defaultTolerance#
Default number of intervals: #defaultNumberOfIntervals#
Optimization level: #optlevel#

diff --git a/resultsdb.py b/resultsdb.py index 88525f0..1c826a0 100644 --- a/resultsdb.py +++ b/resultsdb.py @@ -365,9 +365,7 @@ def __init__(self, url): self.host = hostname() self.claims = [] self.heartbeatThread = None - self.execute(JOB_CLAIM) - self._migrateJobClaim() - self.commit() + self.jobClaimReady = False def _connect(self): """Open the connection, asking the kernel to keep it alive. @@ -419,6 +417,19 @@ def commit(self): self.conn.commit() self.pending = [] + def _prepareJobClaim(self): + """Create and migrate job_claim, the first time a job is claimed. + + Only a test run claims anything, so doing it on connect would make the + report scripts ask for write rights they never use. + """ + if self.jobClaimReady: + return + self.execute(JOB_CLAIM) + self._migrateJobClaim() + self.commit() + self.jobClaimReady = True + def _migrateJobClaim(self): """Narrow an older job_claim to (branch, libname). @@ -539,6 +550,7 @@ def claim(self, branch, libname, libversion, omcversion, confighash): A machine that dies stops sending its heartbeat, and after STALE_CLAIM_MINUTES its jobs are up for grabs again. """ + self._prepareJobClaim() key = (branch, libname) got = self.execute("""INSERT INTO job_claim (branch, libname, libversion, omcversion, confighash, host, state) diff --git a/shared.py b/shared.py index 4ea90c2..f8f3a89 100644 --- a/shared.py +++ b/shared.py @@ -1,8 +1,12 @@ #!/usr/bin/env python3 -import re, os, string, subprocess +import re, os, signal, string, subprocess import simplejson as json +# Windows has no SIGKILL, and no process group to signal instead; os.kill there +# is TerminateProcess whichever signal it is handed. +SIGKILL = getattr(signal, "SIGKILL", signal.SIGTERM) + # A job is named after the branch it tests, and takes the last part of the name: # maintenance/v1.27 is stored and published as v1.27. A pull request is the # exception - pr/16370 keeps the directory it is in, so that the branches @@ -13,6 +17,10 @@ def resultTable(branch): """The results of a job named after this branch: its table and its directory.""" return branch if prBranchRe.match(branch) else branch.split("/")[-1] +# How long a model may simulate when nothing asks for longer; update-ulimit-exe.py +# derives it, and the exceptions, from the master results. +DEFAULT_ULIMIT_EXE = 240 + simCodeTargetRe = re.compile('--simCodeTarget=([^"\'\\s,;)]+)') def simCodeTargetFromCommands(target, commands): @@ -47,7 +55,8 @@ def fixData(data,abortSimulationFlag,alarmFlag,overrideDefaults,defaultCustomCom # actually use, so the rest of the testing scripts need to see it data["simCodeTarget"] = simCodeTargetFromCommands(data["simCodeTarget"], data["customCommands"]) data["ulimitOmc"] = int(data.get("ulimitOmc") or 660) # 11 minutes to generate the C-code - data["ulimitExe"] = int(data.get("ulimitExe") or 8*60) # 8 additional minutes to initialize and run the simulation + data["ulimitExe"] = int(data.get("ulimitExe") or DEFAULT_ULIMIT_EXE) + data["ulimitExeModels"] = dict((k,int(v)) for (k,v) in (data.get("ulimitExeModels") or {}).items()) data["ulimitLoadModel"] = int(data.get("ulimitLoadModel") or 3*60) # 3 minutes to load the files (could take a while if the ssd is doing backup) simflags = [] if data.get("extraSimFlags"): @@ -68,6 +77,7 @@ def fixData(data,abortSimulationFlag,alarmFlag,overrideDefaults,defaultCustomCom data["libraryVersionExactMatch"] = data.get("libraryVersionExactMatch") or False data["alarmFlag"] = data.get("alarmFlag") or (alarmFlag if data["simCodeTarget"] in ("C","wasm-jit") else "") data["abortSlowSimulation"] = data.get("abortSlowSimulation") or (abortSimulationFlag if data["simCodeTarget"]=="C" else "") + data["simFlags"] = simulationFlags(data, data["ulimitExe"]) if "changeHash" in data: # Force rebuilding the library due to change in the testing script data["changeHash"] = data["changeHash"] return (data["library"],data) @@ -75,6 +85,17 @@ def fixData(data,abortSimulationFlag,alarmFlag,overrideDefaults,defaultCustomCom print("Failed to fix data for: %s with extra args: %s" % (str(data),str((abortSimulationFlag,alarmFlag,defaultCustomCommands)))) raise +def modelUlimitExe(conf, modelName): + """How long that model may simulate: what its library allows, unless the model + is one of the few named in ulimitExeModels.""" + return conf["ulimitExeModels"].get(modelName) or conf["ulimitExe"] + +def simulationFlags(conf, ulimitExe): + """The flags a simulation allowed that many seconds is run with.""" + if conf["alarmFlag"] == "": + return "%s %s" % (conf["abortSlowSimulation"],conf["extraSimFlags"]) + return "%s %s=%d %s" % (conf["abortSlowSimulation"],conf["alarmFlag"],ulimitExe,conf["extraSimFlags"]) + def readConfig(c,abortSimulationFlag="",alarmFlag="",overrideDefaults=[],defaultCustomCommands=[],extrasimflags="",environmentTranslation=[],environmentSimulation=[]): return [fixData(data,abortSimulationFlag,alarmFlag,overrideDefaults,defaultCustomCommands,extrasimflags,environmentTranslation,environmentSimulation) for data in json.load(open(c))] diff --git a/test.py b/test.py index 57b018a..1bc831f 100755 --- a/test.py +++ b/test.py @@ -16,7 +16,7 @@ from monotonic import monotonic from omcommon import friendlyStr, multiple_replace from natsort import natsorted -from shared import readConfig, getReferenceFileName, simulationAcceptsFlag, isFMPy +from shared import readConfig, getReferenceFileName, simulationAcceptsFlag, isFMPy, modelUlimitExe, simulationFlags from platform import processor import shared, resultsdb @@ -203,6 +203,19 @@ def print_linenum(signum, frame): print("Created files directory") sys.stdout.flush() +def killTree(pid, sig): + """Signal a process and everything it started; on Windows the shell the command + runs in is a process of its own, and killing it leaves the command running.""" + try: + procs = [psutil.Process(pid)] + psutil.Process(pid).children(recursive=True) + except psutil.Error: + return + for process in procs: + try: + os.kill(process.pid, sig) + except (OSError, psutil.Error): + pass + def runCommand(cmd, prefix, timeout): process = [None] def target(): @@ -220,7 +233,7 @@ def target(): process[0].wait(1) - thread = threading.Thread(target=target) + thread = threading.Thread(target=target, daemon=True) thread.start() thread.join(timeout) @@ -229,16 +242,16 @@ def target(): if thread.is_alive(): gotTimeout = True if isWin: - os.kill(process[0].pid, signal.SIGTERM) + killTree(process[0].pid, signal.SIGTERM) else: os.kill(-process[0].pid, signal.SIGTERM) thread.join(min(10, timeout)) if thread.is_alive(): if isWin: - os.kill(process[0].pid, signal.SIGKILL) + killTree(process[0].pid, shared.SIGKILL) else: - os.kill(-process[0].pid, signal.SIGKILL) - thread.join() + os.kill(-process[0].pid, shared.SIGKILL) + thread.join(10) if clean: try: @@ -849,10 +862,9 @@ def simulatorKey(libname, runner): errorOccurred=False for (modelName,library,libName,name,conf) in tests: - if conf["alarmFlag"]!="": - conf["simFlags"]="%s %s=%d %s" % (conf["abortSlowSimulation"],conf["alarmFlag"],conf["ulimitExe"],conf["extraSimFlags"]) - else: - conf["simFlags"]="%s %s" % (conf["abortSlowSimulation"],conf["extraSimFlags"]) + # conf is shared by every test of the library, so these stay local. + ulimitExe = modelUlimitExe(conf, modelName) + simFlags = simulationFlags(conf, ulimitExe) replacements = ( (u"#logFile#", "/tmp/OpenModelicaLibraryTesting.log"), (u"#library#", library), @@ -866,7 +878,7 @@ def simulatorKey(libname, runner): (u"#reference_reltol#", str(conf["reference_reltol"])), (u"#reference_reltolDiffMinMax#", str(conf["reference_reltolDiffMinMax"])), (u"#reference_rangeDelta#", str(conf["reference_rangeDelta"])), - (u"#simFlags#", conf["simFlags"]), + (u"#simFlags#", simFlags), (u"#referenceFiles#", str(conf.get("referenceFilesURL") or conf.get("referenceFiles") or "")), (u"#referenceFileNameDelimiter#", conf["referenceFileNameDelimiter"]), (u"#referenceFileExtension#", conf["referenceFileExtension"]), @@ -884,6 +896,8 @@ def simulatorKey(libname, runner): newconf["library"] = library newconf["modelName"] = modelName newconf["fileName"] = name + newconf["ulimitExe"] = ulimitExe + newconf["simFlags"] = simFlags try: newconf["referenceFile"] = getReferenceFileName(newconf).replace("\\","/") except Exception as e: @@ -994,7 +1008,7 @@ def expectedExec(c): if customTimeout > 0.0: cmd_res=Parallel(n_jobs=n_jobs, verbose=verbose)(delayed(runScript)(name, customTimeout, data["ulimitMemory"], runverbose) for (model,lib,libName,name,data) in tests) else: - cmd_res=Parallel(n_jobs=n_jobs, verbose=verbose)(delayed(runScript)(name, 2*data["ulimitOmc"]+data["ulimitExe"]+25, data["ulimitMemory"], runverbose) for (model,lib,libName,name,data) in tests) + cmd_res=Parallel(n_jobs=n_jobs, verbose=verbose)(delayed(runScript)(name, 2*data["ulimitOmc"]+modelUlimitExe(data, model)+25, data["ulimitMemory"], runverbose) for (model,lib,libName,name,data) in tests) stop=monotonic() print("Execution time: %s" % friendlyStr(stop-start)) assert(stop-start >= 0.0) @@ -1386,6 +1400,8 @@ def artifactSuffix(simulator): (u"#metadata#", html.escape(conf["metadata"])), (u"#ulimitOmc#", html.escape(str(conf["ulimitOmc"]))), (u"#ulimitExe#", html.escape(str(conf["ulimitExe"]))), + (u"#ulimitExeModels#", "".join("Simulation time limit for %s: %ds
\n" % (html.escape(m), t) + for (m,t) in sorted(conf["ulimitExeModels"].items()))), (u"#defaultTolerance#", html.escape(str(conf["defaultTolerance"]))), (u"#defaultNumberOfIntervals#", html.escape(str(conf["defaultNumberOfIntervals"]))), (u"#simFlags#", html.escape(conf.get("simFlags") or "")), diff --git a/testmodel.py b/testmodel.py index 9555f21..0344137 100755 --- a/testmodel.py +++ b/testmodel.py @@ -112,6 +112,16 @@ def writeResultAndExit(exitStatus, useOsExit=False, omc=None, omc_new=None): else: sys.exit(exitStatus) +def killChildren(sig, name): + """Signal everything this process started, one process at a time: Windows has no + process group to signal instead.""" + for process in psutil.Process().children(recursive=True): + try: + os.kill(process.pid, sig) + except (OSError, psutil.Error): + with open(errFile, 'a+') as fp: + fp.write("Could not %s process: %s.\n" % (name, process.pid)) + def sendExpressionTimeout(omc, cmd, timeout): with open(errFile, 'a+') as fp: fp.write("%s [Timeout %s]\n" % (cmd, timeout)) @@ -128,11 +138,12 @@ def target(res): res[1] = cmd + " " + str(e) res=[None,None] - thread = threading.Thread(target=target, args=(res,)) + # A daemon thread, so that one stuck in a ZMQ receive cannot keep the process + # alive past the exit below + thread = threading.Thread(target=target, args=(res,), daemon=True) thread.start() # Poll instead of a single join: if omc dies (crash, ulimit, ...) the thread is - # stuck in a ZMQ receive that never returns, so waiting out the timeout and then - # exiting normally would hang forever on that non-daemon thread + # stuck in that receive, and waiting out the whole timeout first buys nothing deadline = monotonic() + timeout while thread.is_alive() and monotonic() < deadline: thread.join(1) @@ -157,22 +168,10 @@ def target(res): for line in omcLog: fp.write(line) print("OMC died, but the thread is still running? This will end badly.\n") - for process in psutil.Process().children(recursive=True): - try: - os.kill(process.pid, signal.SIGINT) - except OSError: - with open(errFile, 'a+') as fp: - fp.write("Could not SIGINT process: %s.\n" % process.pid) - pass + killChildren(signal.SIGINT, "SIGINT") thread.join(2) if thread.is_alive(): - for process in psutil.Process().children(recursive=True): - try: - os.kill(process.pid, signal.SIGKILL) - except OSError: - with open(errFile, 'a+') as fp: - fp.write("Could not SIGKILL process: %s.\n" % process.pid) - pass + killChildren(shared.SIGKILL, "SIGKILL") with open(errFile, 'a+') as fp: fp.write("Aborted the command.\n") writeResultAndExit(0, True, omc, omc_new) @@ -200,28 +199,16 @@ def target(res): res[1] = cmd + " " + str(e) res=[None,None] - thread = threading.Thread(target=target, args=(res,)) + thread = threading.Thread(target=target, args=(res,), daemon=True) thread.start() thread.join(timeout) if thread.is_alive(): - for process in psutil.Process().children(recursive=True): - try: - os.killpg(process.pid, signal.SIGINT) - except OSError: - with open(errFile, 'a+') as fp: - fp.write("Could not SIGINT process: %s.\n" % process.pid) - pass + killChildren(signal.SIGINT, "SIGINT") thread.join(2) if thread.is_alive(): - for process in psutil.Process().children(recursive=True): - try: - os.kill(process.pid, signal.SIGKILL) - except OSError: - with open(errFile, 'a+') as fp: - fp.write("Could not SIGKILL process: %s.\n" % process.pid) - pass - thread.join() + killChildren(shared.SIGKILL, "SIGKILL") + thread.join(2) if res[1] is None: res[1] = "" if res[1] is not None: diff --git a/update-ulimit-exe.py b/update-ulimit-exe.py new file mode 100755 index 0000000..1f648e8 --- /dev/null +++ b/update-ulimit-exe.py @@ -0,0 +1,284 @@ +#!/usr/bin/env python3 +""" +Set how long every model of a library may spend simulating, from what it has +spent: `ulimitExe` for the library, `ulimitExeModels` for the models that have +earned longer than that. + + ./update-ulimit-exe.py --db postgresql://om@openmodelica.org/omdb configs/conf.json + ./update-ulimit-exe.py --db postgresql://om@openmodelica.org/omdb --write configs/*.json + +The first prints what would change, the second changes it in place, leaving the +rest of the file - key order, indentation, tabs and all - alone. Neither writes +to the database, so a read-only user is enough for both. + +A model is allowed --factor times the longest it has taken over --runs runs of +--branch, master by default: it runs on the slower of the test machines, so a +model fast enough there is fast enough everywhere. Both halves of that matter - +the same model has been seen to take six times its usual time when the machine +is busy, so a handful of runs does not show what a model needs, and the longest +of a few months of them still wants a margin on top. Only runs that finished +simulating are read; one killed by the timeout has no time to measure, and is +reported rather than guessed at. +""" + +import argparse, math, re +import simplejson as json +import resultsdb, shared + +# Rounding the timeouts keeps a re-run from rewriting them over rounding noise. +STEP = 30 + +# A run that spent this much of its timeout and still failed was killed by it. +KILLED_FRACTION = 0.95 + + +def roundUp(seconds): + return int(math.ceil(seconds / float(STEP)) * STEP) + + +def lastRuns(cursor, db, branch, runs): + """The dates of the newest runs of that branch, newest first.""" + return [row[0] for row in cursor.execute( + "SELECT DISTINCT date FROM %s ORDER BY date DESC LIMIT %d" % (db.quote(branch), runs))] + + +def simulationTimes(cursor, db, branches, runs): + """For every model of every library, the longest it has been seen to simulate + and the longest it ran before failing, over the newest runs of each branch.""" + best = {} + failed = {} + for branch in branches: + dates = lastRuns(cursor, db, branch, runs) + if not dates: + print("No results for branch %s" % branch) + continue + holes = ",".join("?" * len(dates)) + for (libname, model, finalphase, simulate) in cursor.execute( + "SELECT libname, model, finalphase, MAX(simulate) FROM %s WHERE date IN (%s) " + "GROUP BY libname, model, finalphase" % (db.quote(branch), holes), tuple(dates)): + key = (libname, model) + target = best if finalphase >= 6 else failed + target[key] = max(target.get(key, 0.0), simulate) + return (best, failed) + + +def libraryLimit(entry, default): + """The timeout the models of that library get without one of their own.""" + return int(entry.get("ulimitExe") or default) + + +def wanted(entry, libname, best, failed, default, factor): + """That library's timeout, the models allowed longer and the models that were + killed, or None for a library the database has never heard of - guessing there + would replace a hand-written timeout with a default nobody measured.""" + measured = dict((model, t) for ((lib, model), t) in best.items() if lib == libname) + killed = dict((model, t) for ((lib, model), t) in failed.items() if lib == libname) + if not measured and not killed: + return None + # A timeout under the default is a deliberately short one and stays; a longer + # one is what the named models replaced. + limit = min(libraryLimit(entry, default), default) + models = dict((model, roundUp(t * factor)) for (model, t) in measured.items() if t > limit) + inForce = lambda model: (entry.get("ulimitExeModels") or {}).get(model) \ + or libraryLimit(entry, default) + wasKilled = sorted(model for (model, t) in killed.items() + if t >= KILLED_FRACTION * inForce(model)) + return (limit, models, wasKilled) + + +def entrySpans(text): + """Where each library entry starts and ends: the objects directly inside the + outermost list. The files are edited as text rather than re-serialised, so + that setting one number does not reformat the other ninety-five entries.""" + spans = [] + depth = 0 + start = None + inString = False + escaped = False + for (i, ch) in enumerate(text): + if inString: + if escaped: + escaped = False + elif ch == "\\": + escaped = True + elif ch == '"': + inString = False + continue + if ch == '"': + inString = True + elif ch in "[{": + depth = depth + 1 + if depth == 2 and ch == "{": + start = i + elif ch in "]}": + if depth == 2 and ch == "}" and start is not None: + spans.append((start, i + 1)) + start = None + depth = depth - 1 + return spans + + +keyRe = re.compile(r'^(\s*)"([A-Za-z]+)"\s*:') + +# A new timeout goes after these, where the hand-written ones are. +AFTER_KEYS = ["ulimitOmc", "libraryVersionNameForTests", "libraryVersionExactMatch", + "libraryVersion", "library"] + + +def rewriteEntry(entry, limit, models, default): + """That entry's text with its timeouts replaced by these, and nothing else + touched. The keys are dropped rather than written out when they say nothing.""" + lines = entry.split("\n") + out = [] + indent = " " + skipTo = None + for (i, line) in enumerate(lines): + if skipTo is not None: + if i < skipTo: + continue + skipTo = None + m = keyRe.match(line) + if m and m.group(2) in ("ulimitExe", "ulimitExeModels"): + indent = m.group(1) + if m.group(2) == "ulimitExeModels" and not line.rstrip().endswith(("}", "},")): + # A block spanning several lines ends at the first line that closes it. + skipTo = next(j for j in range(i + 1, len(lines)) + if lines[j].strip() in ("}", "},")) + 1 + continue + if m and m.group(2) in AFTER_KEYS: + indent = m.group(1) + out.append(line) + written = [] + if limit != default: + written.append('%s"ulimitExe":%d,' % (indent, limit)) + if models: + written.append('%s"ulimitExeModels":{' % indent) + for (i, model) in enumerate(sorted(models)): + written.append('%s "%s":%d%s' % (indent, model, models[model], + "" if i == len(models) - 1 else ",")) + written.append("%s}," % indent) + # After the last of the keys that name the library, or first if it has none. + at = 1 + for (i, line) in enumerate(out): + m = keyRe.match(line) + if m and m.group(2) in AFTER_KEYS: + at = i + 1 + lines = out[:at] + written + out[at:] + # Inserting or removing a block moves which key is the last one, the only one + # without a comma. + if written and at > 0: + lines[at - 1] = lines[at - 1].rstrip().rstrip(",") + "," + if len(lines) > 1 and lines[-1].strip() == "}": + lines[-2] = lines[-2].rstrip().rstrip(",") + return "\n".join(lines) + + +def describe(libname, entry, limit, models, wasKilled, default): + """What changes for that library, or nothing when it already says this.""" + was = (libraryLimit(entry, default), entry.get("ulimitExeModels") or {}) + now = (limit, models) + lines = [] + if was[0] != now[0]: + lines.append(" timeout %ds -> %ds" % (was[0], now[0])) + for model in sorted(set(list(was[1]) + list(now[1]))): + old = was[1].get(model) + new = now[1].get(model) + if old == new: + continue + elif old is None: + lines.append(" + %s %ds" % (model, new)) + elif new is None: + lines.append(" - %s (was %ds, no longer needed)" % (model, old)) + else: + lines.append(" ~ %s %ds -> %ds" % (model, old, new)) + for model in wasKilled: + lines.append(" ! %s ran into the timeout in force, so there is nothing to measure" % model) + if lines: + lines.insert(0, "%s:" % libname) + return lines + + +def main(): + parser = argparse.ArgumentParser( + description="Set the simulation timeouts of the tested libraries from their results", + formatter_class=argparse.RawDescriptionHelpFormatter, epilog=__doc__) + parser.add_argument("configs", nargs="+") + parser.add_argument("--branch", default="master", + help="Branch whose results decide the timeouts, or several separated by " + "spaces, in which case each model is allowed what the slowest of them " + "needed. Defaults to master, which runs on the slower test machines.") + parser.add_argument("--runs", type=int, default=100, + help="How many of the newest runs of each branch to read (default 100). " + "Fewer than a few dozen and the occasional slow run is missed.") + parser.add_argument("--factor", type=float, default=1.25, + help="How much longer than it has ever taken a model is allowed " + "(default 1.25)") + parser.add_argument("--default", type=int, default=shared.DEFAULT_ULIMIT_EXE, + help="The timeout a model gets when nothing asks for another, which is " + "what shared.py says unless overridden here") + parser.add_argument("--write", action="store_true", + help="Change the configuration files instead of only saying what would change") + resultsdb.addArgument(parser) + args = parser.parse_args() + + db = resultsdb.connect(args.db) + cursor = db.cursor() + branches = [shared.resultTable(b) for b in args.branch.split(" ") if b] + (best, failed) = simulationTimes(cursor, db, branches, args.runs) + + changed = False + for path in args.configs: + entries = shared.readConfig(path) + text = open(path).read() + spans = entrySpans(text) + if len(spans) != len(entries): + raise SystemExit("%s: found %d entries but %d objects in the file" + % (path, len(entries), len(spans))) + report = [] + pieces = [] + intended = [] + at = 0 + for ((library, conf), (start, end)) in zip(entries, spans): + raw = conf["configFromFile"] + libname = shared.libname(library, conf) + w = wanted(raw, libname, best, failed, args.default, args.factor) + pieces.append(text[at:start]) + at = end + if w is None: + report.append("%s: no results on %s, left alone" % (libname, ", ".join(branches))) + pieces.append(text[start:end]) + intended.append(dict(raw)) + continue + (limit, models, wasKilled) = w + report.extend(describe(libname, raw, limit, models, wasKilled, args.default)) + pieces.append(rewriteEntry(text[start:end], limit, models, args.default)) + entry = dict(raw) + entry.pop("ulimitExe", None) + entry.pop("ulimitExeModels", None) + if limit != args.default: + entry["ulimitExe"] = limit + if models: + entry["ulimitExeModels"] = models + intended.append(entry) + pieces.append(text[at:]) + new = "".join(pieces) + + print("== %s" % path) + print("\n".join(report) if report else " nothing to change") + if new == text: + continue + changed = True + # Editing the text keeps the formatting; it must not cost the contents. + if json.loads(new) != intended: + raise SystemExit("%s: the rewritten file does not say what it was meant to say; " + "not writing it" % path) + if args.write: + open(path, "w").write(new) + print(" written") + + if changed and not args.write: + print("\nNothing was written. Pass --write to change the files.") + + +if __name__ == "__main__": + main()