Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr ThermalSeparation_ThermalSeparation.Examples.Testing.Pump.PumpSystem.conf.json
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaServices 4.1.0+maint.om/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaServices 4.1.0+maint.om/package.mo): time 0.001656/0.001656, allocations: 114.8 kB / 17.13 MB, free: 6.027 MB / 14.72 MB
"
[Timeout remaining time 180]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/Complex 4.1.0+maint.om/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/Complex 4.1.0+maint.om/package.mo): time 0.001572/0.001572, allocations: 207.2 kB / 20.1 MB, free: 3.074 MB / 14.72 MB
"
[Timeout remaining time 180]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica 4.1.0+maint.om/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica 4.1.0+maint.om/package.mo): time 1.496/1.496, allocations: 230.6 MB / 253.5 MB, free: 15.11 MB / 206.1 MB
"
[Timeout remaining time 178]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/ThermalSeparation 0.2.0-master/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/ThermalSeparation 0.2.0-master/package.mo): time 0.4038/0.4038, allocations: 65.54 MB / 375.1 MB, free: 8.508 MB / 302.1 MB
"
[Timeout remaining time 179]
Using package ThermalSeparation with version 0.2 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/ThermalSeparation 0.2.0-master/package.mo)
Using package Modelica with version 4.1.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica 4.1.0+maint.om/package.mo)
Using package Complex with version 4.1.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/Complex 4.1.0+maint.om/package.mo)
Using package ModelicaServices with version 4.1.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaServices 4.1.0+maint.om/package.mo)
Running command: "" <> buildModelFMU(ThermalSeparation.Examples.Testing.Pump.PumpSystem,fileNamePrefix="ThermalSeparation_ThermalSeparation_Examples_Testing_Pump_PumpSystem",fmuType="me",version="2.0",platforms={"static"})
"" <> buildModelFMU(ThermalSeparation.Examples.Testing.Pump.PumpSystem,fileNamePrefix="ThermalSeparation_ThermalSeparation_Examples_Testing_Pump_PumpSystem",fmuType="me",version="2.0",platforms={"static"}) [Timeout 660]
"Notification: ThermalSeparation requested package Modelica of version 4.0.0. Modelica 4.1.0 is used instead which states that it is fully compatible without conversion script needed.
Notification: Performance of FrontEnd - loaded program: time 0.002103/0.002103, allocations: 67.88 kB / 0.5124 GB, free: 11.7 MB / 382.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.163/0.1651, allocations: 68.01 MB / 0.5788 GB, free: 7.543 MB / 446.1 MB
Notification: Performance of NFInst.instantiate(ThermalSeparation.Examples.Testing.Pump.PumpSystem): time 0.01034/0.1754, allocations: 7.429 MB / 0.586 GB, free: 84 kB / 446.1 MB
Notification: Performance of NFInst.instExpressions: time 0.3601/0.5355, allocations: 4.461 MB / 0.5904 GB, free: 7.934 MB / 446.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.001028/0.5365, allocations: 12.75 kB / 0.5904 GB, free: 7.93 MB / 446.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.001566/0.5381, allocations: 0.5618 MB / 0.591 GB, free: 7.766 MB / 446.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.001834/0.5399, allocations: 0.7207 MB / 0.5917 GB, free: 7.516 MB / 446.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.00132/0.5412, allocations: 0.5258 MB / 0.5922 GB, free: 7.5 MB / 446.1 MB
Notification: Performance of NFFlatten.flatten: time 0.003782/0.545, allocations: 2.461 MB / 0.5946 GB, free: 6.805 MB / 446.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.001274/0.5463, allocations: 0.6387 MB / 0.5952 GB, free: 6.516 MB / 446.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.001922/0.5482, allocations: 0.8817 MB / 0.5961 GB, free: 6.16 MB / 446.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.002106/0.5503, allocations: 1.091 MB / 0.5971 GB, free: 5.762 MB / 446.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.0003756/0.5507, allocations: 207.4 kB / 0.5973 GB, free: 5.762 MB / 446.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.0006031/0.5513, allocations: 206.8 kB / 0.5975 GB, free: 5.762 MB / 446.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.0008007/0.5521, allocations: 0.8052 MB / 0.5983 GB, free: 5.41 MB / 446.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.001391/0.5535, allocations: 1.093 MB / 0.5994 GB, free: 4.742 MB / 446.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.004303/0.5578, allocations: 3.082 MB / 0.6024 GB, free: 3.707 MB / 446.1 MB
Notification: Performance of FrontEnd - DAE generated: time 9.618e-06/0.5578, allocations: 5.094 kB / 0.6024 GB, free: 3.703 MB / 446.1 MB
Notification: Performance of FrontEnd: time 2.725e-06/0.5578, allocations: 0 / 0.6024 GB, free: 3.703 MB / 446.1 MB
Notification: Performance of Transformations before backend: time 0.0001216/0.5579, allocations: 0 / 0.6024 GB, free: 3.703 MB / 446.1 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 546
 * Number of variables: 546
Notification: Performance of Generate backend data structure: time 0.005803/0.5637, allocations: 2.196 MB / 0.6045 GB, free: 2.461 MB / 446.1 MB
Notification: Performance of prepare preOptimizeDAE: time 5.325e-05/0.5638, allocations: 12.44 kB / 0.6046 GB, free: 2.457 MB / 446.1 MB
Notification: Performance of preOpt introduceOutputAliases (simulation): time 0.0004552/0.5642, allocations: 300.4 kB / 0.6048 GB, free: 2.281 MB / 446.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.0008748/0.5651, allocations: 233.4 kB / 0.6051 GB, free: 2.176 MB / 446.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.001394/0.5665, allocations: 0.7527 MB / 0.6058 GB, free: 1.633 MB / 446.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0001509/0.5667, allocations: 147.4 kB / 0.6059 GB, free: 1.57 MB / 446.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0008156/0.5675, allocations: 273.4 kB / 0.6062 GB, free: 1.5 MB / 446.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.004965/0.5724, allocations: 2.729 MB / 0.6089 GB, free: 112 kB / 446.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 4.964e-05/0.5725, allocations: 7.688 kB / 0.6089 GB, free: 108 kB / 446.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.000216/0.5727, allocations: 95.73 kB / 0.609 GB, free: 36 kB / 446.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.0002694/0.573, allocations: 148.7 kB / 0.6091 GB, free: 20 kB / 446.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.006419/0.5794, allocations: 2.226 MB / 0.6113 GB, free: 15.2 MB / 462.1 MB
Warning: The model contains alias variables with redundant start and/or conflicting nominal values. It is recommended to resolve the conflicts, because otherwise the system could be hard to solve. To print the conflicting alias sets and the chosen candidates please use -d=aliasConflicts.
Notification: Performance of preOpt removeSimpleEquations (simulation): time 0.01778/0.5972, allocations: 10.83 MB / 0.6219 GB, free: 5.824 MB / 462.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.003245/0.6004, allocations: 2.714 MB / 0.6245 GB, free: 3.137 MB / 462.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.001318/0.6017, allocations: 0.593 MB / 0.6251 GB, free: 2.805 MB / 462.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.0001152/0.6019, allocations: 28.7 kB / 0.6251 GB, free: 2.793 MB / 462.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 5.059e-05/0.6019, allocations: 48.06 kB / 0.6252 GB, free: 2.742 MB / 462.1 MB
Notification: Performance of pre-optimization done (n=115): time 3.237e-06/0.6019, allocations: 4 kB / 0.6252 GB, free: 2.738 MB / 462.1 MB
Notification: Performance of matching and sorting (n=140): time 0.02351/0.6254, allocations: 7.671 MB / 0.6327 GB, free: 14.05 MB / 478.1 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.005778/0.6312, allocations: 4.11 MB / 0.6367 GB, free: 10.2 MB / 478.1 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.002053/0.6333, allocations: 1.084 MB / 0.6377 GB, free: 9.578 MB / 478.1 MB
Notification: Performance of collectPreVariables (initialization): time 0.0004418/0.6337, allocations: 58.5 kB / 0.6378 GB, free: 9.52 MB / 478.1 MB
Notification: Performance of collectInitialEqns (initialization): time 0.0009165/0.6346, allocations: 0.9713 MB / 0.6387 GB, free: 8.645 MB / 478.1 MB
Notification: Performance of collectInitialBindings (initialization): time 0.0008988/0.6355, allocations: 0.518 MB / 0.6392 GB, free: 8.188 MB / 478.1 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.0008682/0.6364, allocations: 438.2 kB / 0.6397 GB, free: 7.934 MB / 478.1 MB
Notification: Performance of setup shared object (initialization): time 0.0002317/0.6366, allocations: 344.6 kB / 0.64 GB, free: 7.602 MB / 478.1 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.001931/0.6385, allocations: 0.9163 MB / 0.6409 GB, free: 7.137 MB / 478.1 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.002724/0.6413, allocations: 1.878 MB / 0.6427 GB, free: 5.355 MB / 478.1 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.004904/0.6462, allocations: 2.953 MB / 0.6456 GB, free: 2.965 MB / 478.1 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 3.422e-05/0.6462, allocations: 9.625 kB / 0.6456 GB, free: 2.965 MB / 478.1 MB
Notification: Performance of matching and sorting (n=301) (initialization): time 0.01048/0.6567, allocations: 3.688 MB / 0.6492 GB, free: 15.39 MB / 494.1 MB
Notification: Performance of prepare postOptimizeDAE: time 4.753e-05/0.6567, allocations: 20 kB / 0.6492 GB, free: 15.37 MB / 494.1 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 6.211e-05/0.6568, allocations: 32 kB / 0.6493 GB, free: 15.34 MB / 494.1 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.004877/0.6617, allocations: 0.9841 MB / 0.6502 GB, free: 14.35 MB / 494.1 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.003333/0.665, allocations: 0.5615 MB / 0.6508 GB, free: 13.79 MB / 494.1 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.01231/0.6773, allocations: 6.679 MB / 0.6573 GB, free: 6.918 MB / 494.1 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.002913/0.6802, allocations: 163.8 kB / 0.6574 GB, free: 6.758 MB / 494.1 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0006163/0.6808, allocations: 124 kB / 0.6576 GB, free: 6.637 MB / 494.1 MB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 147
 * Number of states: 0 ()
 * Number of discrete variables: 5 (tank.mediumLiquidIn.state.phase,tank.mediumLiquid.state.phase,sourceLiquid.medium.state.phase,idealPumpControlledVdot.mediumLiquidIn.state.phase,idealPumpControlledVdot.mediumLiquid.state.phase)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (269):
 * Single equations (assignments): 264
 * Array equations: 2
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 3
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 1 system
   {(9,14,63.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 2 systems
   {(1,3), (1,3)}
Notification: Performance of prepare postOptimizeDAE: time 0.001498/0.6823, allocations: 0.5602 MB / 0.6581 GB, free: 6.066 MB / 494.1 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0004907/0.6828, allocations: 143.1 kB / 0.6582 GB, free: 5.926 MB / 494.1 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.008575/0.6914, allocations: 2.843 MB / 0.661 GB, free: 3.055 MB / 494.1 MB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 0.007728/0.6991, allocations: 2.469 MB / 0.6634 GB, free: 0.5625 MB / 494.1 MB
Notification: Performance of postOpt constantLinearSystem (simulation): time 2.308e-05/0.6992, allocations: 8 kB / 0.6634 GB, free: 0.5547 MB / 494.1 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 4.294e-05/0.6992, allocations: 7.969 kB / 0.6634 GB, free: 0.5469 MB / 494.1 MB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.01712/0.7163, allocations: 6.058 MB / 0.6694 GB, free: 10.32 MB / 0.4981 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 2.386e-05/0.7163, allocations: 4 kB / 0.6694 GB, free: 10.31 MB / 0.4981 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.002162/0.7185, allocations: 284.1 kB / 0.6696 GB, free: 10.04 MB / 0.4981 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.005885/0.7244, allocations: 1.194 MB / 0.6708 GB, free: 8.828 MB / 0.4981 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0003834/0.7248, allocations: 39.97 kB / 0.6708 GB, free: 8.789 MB / 0.4981 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.01114/0.7359, allocations: 6.321 MB / 0.677 GB, free: 2.25 MB / 0.4981 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 0.0057/0.7416, allocations: 3.968 MB / 0.6809 GB, free: 13.98 MB / 0.5137 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.01117/0.7528, allocations: 4.321 MB / 0.6851 GB, free: 9.57 MB / 0.5137 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.0006326/0.7534, allocations: 228.2 kB / 0.6853 GB, free: 9.328 MB / 0.5137 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.000565/0.754, allocations: 39.98 kB / 0.6854 GB, free: 9.289 MB / 0.5137 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.001844/0.7558, allocations: 79.91 kB / 0.6854 GB, free: 9.211 MB / 0.5137 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.0004916/0.7563, allocations: 120.6 kB / 0.6856 GB, free: 9.09 MB / 0.5137 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.000197/0.7565, allocations: 51.97 kB / 0.6856 GB, free: 9.039 MB / 0.5137 GB
Notification: Performance of sorting global known variables: time 0.001291/0.7578, allocations: 0.6962 MB / 0.6863 GB, free: 8.332 MB / 0.5137 GB
Notification: Performance of sort global known variables: time 8e-08/0.7578, allocations: 0 / 0.6863 GB, free: 8.332 MB / 0.5137 GB
Notification: Performance of remove unused functions: time 0.003107/0.7609, allocations: 0.5586 MB / 0.6868 GB, free: 7.773 MB / 0.5137 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 26
 * Number of states: 4 ($STATESET1.x[3],$STATESET1.x[2],$STATESET1.x[1],tank.level)
 * Number of discrete variables: 0 ()
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for simulation (126):
 * Single equations (assignments): 122
 * Array equations: 0
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 4
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 1 system
   {(7,10,61.2%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 3 systems
   {(1,3), (5,3), (1,3)}
Notification: Performance of Backend phase and start with SimCode phase: time 0.01137/0.7723, allocations: 4.91 MB / 0.6916 GB, free: 2.758 MB / 0.5137 GB
Notification: Performance of simCode: created initialization part: time 0.008046/0.7803, allocations: 2.564 MB / 0.6941 GB, free: 188 kB / 0.5137 GB
Notification: Performance of simCode: created event and clocks part: time 1.064e-05/0.7803, allocations: 0 / 0.6941 GB, free: 188 kB / 0.5137 GB
Notification: Performance of simCode: created simulation system equations: time 0.0047/0.785, allocations: 1.321 MB / 0.6954 GB, free: 14.85 MB / 0.5294 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.003584/0.7886, allocations: 408.5 kB / 0.6958 GB, free: 14.46 MB / 0.5294 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.04122/0.8298, allocations: 17.74 MB / 0.7131 GB, free: 11.32 MB / 0.545 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.002001/0.8318, allocations: 1.412 MB / 0.7145 GB, free: 9.883 MB / 0.545 GB
Notification: Performance of simCode: alias equations: time 0.001757/0.8336, allocations: 464.6 kB / 0.715 GB, free: 9.422 MB / 0.545 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001228/0.8348, allocations: 0.6437 MB / 0.7156 GB, free: 8.777 MB / 0.545 GB
Notification: Performance of SimCode: time 1.523e-06/0.8348, allocations: 3.938 kB / 0.7156 GB, free: 8.773 MB / 0.545 GB
Notification: Performance of buildModelFMU: Generate the FMI files: time 0.105/0.9398, allocations: 43.62 MB / 0.7582 GB, free: 13.43 MB / 0.5919 GB
Notification: Performance of buildModelFMU: Generate platform static: time 14.8/15.74, allocations: 10.02 kB / 0.7582 GB, free: 13.42 MB / 0.5919 GB
"
[Timeout remaining time 644]
(rm -f ThermalSeparation_ThermalSeparation.Examples.Testing.Pump.PumpSystem.pipe ; mkfifo ThermalSeparation_ThermalSeparation.Examples.Testing.Pump.PumpSystem.pipe ; head -c 1048576 < ThermalSeparation_ThermalSeparation.Examples.Testing.Pump.PumpSystem.pipe >> ../files/ThermalSeparation_ThermalSeparation.Examples.Testing.Pump.PumpSystem.sim & python3 -m fmpy simulate  --output-file ThermalSeparation_ThermalSeparation.Examples.Testing.Pump.PumpSystem_res.csv --start-time 0 --stop-time 1500 --timeout 50 --relative-tolerance 1e-06 --interface-type ModelExchange --solver CVode --output-interval 0.6 ThermalSeparation_ThermalSeparation_Examples_Testing_Pump_PumpSystem.fmu > ThermalSeparation_ThermalSeparation.Examples.Testing.Pump.PumpSystem.pipe 2>&1) [Timeout 52.5]
[Calling os._exit(0), Time elapsed: 19.006137860007584]
Failed to read output from testmodel.py, exit status != 0:
15.859531580004841 15.875506942 15.314235938
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7f6ba040d7e0>