Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr OpenIPSL_dev_OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation.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.001677/0.001677, allocations: 101.5 kB / 19.73 MB, free: 2.23 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.406/1.406, allocations: 230.6 MB / 253.4 MB, free: 14.4 MB / 206.1 MB
"
[Timeout remaining time 178]
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.001469/0.001469, allocations: 213.5 kB / 310 MB, free: 3.125 MB / 238.1 MB
"
[Timeout remaining time 180]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/OpenIPSL master/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/OpenIPSL master/package.mo): time 0.5727/0.5727, allocations: 101.3 MB / 467.8 MB, free: 30.69 MB / 350.1 MB
"
[Timeout remaining time 179]
Using package OpenIPSL with version 3.1.0-dev (/home/hudson/saved_omc/libraries/.openmodelica/libraries/OpenIPSL master/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 Modelica with version 4.1.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica 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(OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation,fileNamePrefix="OpenIPSL_dev_OpenIPSL_Tests_Machines_PSAT_Order2test2_perturbation",fmuType="cs",version="2.0",platforms={"static"})
"" <> buildModelFMU(OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation,fileNamePrefix="OpenIPSL_dev_OpenIPSL_Tests_Machines_PSAT_Order2test2_perturbation",fmuType="cs",version="2.0",platforms={"static"}) [Timeout 660]
"Notification: OpenIPSL requested package Complex of version 4.0.0. Complex 4.1.0 is used instead which states that it is fully compatible without conversion script needed.
Notification: OpenIPSL 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.002416/0.002416, allocations: 87.72 kB / 0.6252 GB, free: 33.18 MB / 446.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.1464/0.1488, allocations: 78.63 MB / 0.702 GB, free: 1.043 MB / 478.1 MB
Notification: Performance of NFInst.instantiate(OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation): time 0.007667/0.1565, allocations: 6.459 MB / 0.7083 GB, free: 10.54 MB / 494.1 MB
Notification: Performance of NFInst.instExpressions: time 0.004461/0.161, allocations: 1.977 MB / 0.7102 GB, free: 8.562 MB / 494.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.0008023/0.1618, allocations: 11.94 kB / 0.7102 GB, free: 8.551 MB / 494.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.00063/0.1624, allocations: 226 kB / 0.7104 GB, free: 8.328 MB / 494.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.002087/0.1645, allocations: 0.7766 MB / 0.7112 GB, free: 7.547 MB / 494.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.001427/0.1659, allocations: 0.632 MB / 0.7118 GB, free: 6.922 MB / 494.1 MB
Notification: Performance of NFFlatten.flatten: time 0.001717/0.1676, allocations: 1.417 MB / 0.7132 GB, free: 5.5 MB / 494.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.000427/0.168, allocations: 232.7 kB / 0.7134 GB, free: 5.262 MB / 494.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.000855/0.1689, allocations: 0.6029 MB / 0.714 GB, free: 4.656 MB / 494.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.0008694/0.1698, allocations: 0.7349 MB / 0.7147 GB, free: 3.918 MB / 494.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.0001525/0.1699, allocations: 100 kB / 0.7148 GB, free: 3.82 MB / 494.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.0005124/0.1704, allocations: 251.9 kB / 0.715 GB, free: 3.574 MB / 494.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.000238/0.1707, allocations: 278.8 kB / 0.7153 GB, free: 3.301 MB / 494.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.0005381/0.1712, allocations: 0.6212 MB / 0.7159 GB, free: 2.676 MB / 494.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.001779/0.173, allocations: 1.525 MB / 0.7174 GB, free: 1.145 MB / 494.1 MB
Notification: Performance of FrontEnd - DAE generated: time 6.272e-06/0.173, allocations: 8 kB / 0.7174 GB, free: 1.137 MB / 494.1 MB
Notification: Performance of FrontEnd: time 1.202e-06/0.173, allocations: 0 / 0.7174 GB, free: 1.137 MB / 494.1 MB
Notification: Performance of Transformations before backend: time 2.258e-05/0.173, allocations: 0 / 0.7174 GB, free: 1.137 MB / 494.1 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 194
 * Number of variables: 194
Notification: Performance of Generate backend data structure: time 0.008311/0.1813, allocations: 2.53 MB / 0.7199 GB, free: 14.57 MB / 0.4981 GB
Notification: Performance of prepare preOptimizeDAE: time 4.862e-05/0.1814, allocations: 8.031 kB / 0.7199 GB, free: 14.56 MB / 0.4981 GB
Notification: Performance of preOpt introduceOutputRealDerivatives (simulation): time 3.235e-05/0.1814, allocations: 22 kB / 0.7199 GB, free: 14.54 MB / 0.4981 GB
Notification: Performance of preOpt introduceOutputAliases (simulation): time 0.0001694/0.1816, allocations: 130.8 kB / 0.72 GB, free: 14.4 MB / 0.4981 GB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.005079/0.1867, allocations: 0.8186 MB / 0.7208 GB, free: 13.58 MB / 0.4981 GB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.001429/0.1881, allocations: 0.7284 MB / 0.7216 GB, free: 12.81 MB / 0.4981 GB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.000346/0.1884, allocations: 311.6 kB / 0.7219 GB, free: 12.45 MB / 0.4981 GB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0001617/0.1886, allocations: 79.95 kB / 0.7219 GB, free: 12.38 MB / 0.4981 GB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.002339/0.1909, allocations: 1.073 MB / 0.723 GB, free: 11.3 MB / 0.4981 GB
Notification: Performance of preOpt findStateOrder (simulation): time 1.653e-05/0.191, allocations: 0 / 0.723 GB, free: 11.3 MB / 0.4981 GB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 9.515e-05/0.1911, allocations: 32 kB / 0.723 GB, free: 11.27 MB / 0.4981 GB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 1.835e-05/0.1911, allocations: 19.94 kB / 0.723 GB, free: 11.25 MB / 0.4981 GB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.002572/0.1936, allocations: 1.124 MB / 0.7241 GB, free: 10.12 MB / 0.4981 GB
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.006035/0.1997, allocations: 3.375 MB / 0.7274 GB, free: 6.602 MB / 0.4981 GB
Notification: Performance of preOpt comSubExp (simulation): time 0.002059/0.2017, allocations: 0.8727 MB / 0.7283 GB, free: 5.727 MB / 0.4981 GB
Notification: Performance of preOpt resolveLoops (simulation): time 0.001625/0.2034, allocations: 0.6953 MB / 0.7289 GB, free: 5.023 MB / 0.4981 GB
Notification: Performance of preOpt evalFunc (simulation): time 9.758e-05/0.2035, allocations: 20.98 kB / 0.729 GB, free: 5 MB / 0.4981 GB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 3.709e-05/0.2035, allocations: 47.5 kB / 0.729 GB, free: 4.945 MB / 0.4981 GB
Notification: Performance of pre-optimization done (n=96): time 2.855e-06/0.2035, allocations: 0 / 0.729 GB, free: 4.945 MB / 0.4981 GB
Notification: Performance of matching and sorting (n=96): time 0.02711/0.2306, allocations: 6.634 MB / 0.7355 GB, free: 14.3 MB / 0.5137 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 6.413e-05/0.2307, allocations: 60.41 kB / 0.7356 GB, free: 14.22 MB / 0.5137 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.00125/0.2319, allocations: 0.8963 MB / 0.7364 GB, free: 13.31 MB / 0.5137 GB
Notification: Performance of collectPreVariables (initialization): time 0.0002011/0.2321, allocations: 37.7 kB / 0.7365 GB, free: 13.27 MB / 0.5137 GB
Notification: Performance of collectInitialEqns (initialization): time 0.0004038/0.2325, allocations: 0.5052 MB / 0.737 GB, free: 12.75 MB / 0.5137 GB
Notification: Performance of collectInitialBindings (initialization): time 0.0003759/0.2329, allocations: 357 kB / 0.7373 GB, free: 12.4 MB / 0.5137 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.0004123/0.2333, allocations: 198.8 kB / 0.7375 GB, free: 12.2 MB / 0.5137 GB
Notification: Performance of setup shared object (initialization): time 0.0001621/0.2335, allocations: 353.9 kB / 0.7378 GB, free: 11.85 MB / 0.5137 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.001695/0.2352, allocations: 0.7053 MB / 0.7385 GB, free: 11.14 MB / 0.5137 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.001781/0.237, allocations: 0.8423 MB / 0.7393 GB, free: 10.27 MB / 0.5137 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.01905/0.256, allocations: 4.9 MB / 0.7441 GB, free: 5.336 MB / 0.5137 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 6.772e-06/0.256, allocations: 0 / 0.7441 GB, free: 5.336 MB / 0.5137 GB
Notification: Performance of matching and sorting (n=143) (initialization): time 0.01434/0.2703, allocations: 4.227 MB / 0.7482 GB, free: 1.094 MB / 0.5137 GB
Notification: Performance of prepare postOptimizeDAE: time 4.088e-05/0.2704, allocations: 7.938 kB / 0.7483 GB, free: 1.086 MB / 0.5137 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 1.502e-05/0.2704, allocations: 7.938 kB / 0.7483 GB, free: 1.078 MB / 0.5137 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.006607/0.277, allocations: 1.87 MB / 0.7501 GB, free: 15.2 MB / 0.5294 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.001115/0.2781, allocations: 195.8 kB / 0.7503 GB, free: 15.01 MB / 0.5294 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.02219/0.3003, allocations: 8.992 MB / 0.7591 GB, free: 5.902 MB / 0.5294 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.001518/0.3018, allocations: 187.2 kB / 0.7592 GB, free: 5.719 MB / 0.5294 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0002156/0.302, allocations: 39.98 kB / 0.7593 GB, free: 5.68 MB / 0.5294 GB
Warning: Assuming fixed start value for the following 2 variables:
         order2_Inputs_Outputs1.w:VARIABLE(flow=false start = 1.0 fixed = true )  \"Rotor speed [pu]\" type: Real
         order2_Inputs_Outputs1.delta:VARIABLE(flow=false start = order2_Inputs_Outputs1.delta0 unit = \"rad\" fixed = true )  \"Rotor angle\" type: Real
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 10
 * Number of states: 0 ()
 * Number of discrete variables: 0 ()
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (108):
 * Single equations (assignments): 107
 * Array equations: 0
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 1
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 0 systems
 * Non-linear torn systems (#iteration vars, #inner vars): 1 system
   {(26,10)}
Notification: Performance of prepare postOptimizeDAE: time 0.0006799/0.3027, allocations: 241.6 kB / 0.7595 GB, free: 5.434 MB / 0.5294 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0003245/0.303, allocations: 123.2 kB / 0.7596 GB, free: 5.312 MB / 0.5294 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.01354/0.3166, allocations: 3.975 MB / 0.7635 GB, free: 1.316 MB / 0.5294 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 2.043e-05/0.3166, allocations: 15.94 kB / 0.7635 GB, free: 1.301 MB / 0.5294 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 3.306e-06/0.3166, allocations: 0 / 0.7635 GB, free: 1.301 MB / 0.5294 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 2.283e-05/0.3166, allocations: 7.969 kB / 0.7635 GB, free: 1.293 MB / 0.5294 GB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.01573/0.3324, allocations: 5.559 MB / 0.769 GB, free: 11.6 MB / 0.545 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 1.275e-05/0.3324, allocations: 0 / 0.769 GB, free: 11.6 MB / 0.545 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.0007809/0.3332, allocations: 127.8 kB / 0.7691 GB, free: 11.48 MB / 0.545 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.006155/0.3393, allocations: 1.738 MB / 0.7708 GB, free: 9.734 MB / 0.545 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0002508/0.3396, allocations: 16 kB / 0.7708 GB, free: 9.719 MB / 0.545 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.01992/0.3595, allocations: 7.985 MB / 0.7786 GB, free: 1.613 MB / 0.545 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 2.405e-06/0.3595, allocations: 4 kB / 0.7786 GB, free: 1.609 MB / 0.545 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.01544/0.3749, allocations: 4.945 MB / 0.7834 GB, free: 12.64 MB / 0.5606 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.0003621/0.3753, allocations: 127 kB / 0.7835 GB, free: 12.52 MB / 0.5606 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.000281/0.3756, allocations: 16 kB / 0.7836 GB, free: 12.5 MB / 0.5606 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.001148/0.3767, allocations: 107.9 kB / 0.7837 GB, free: 12.4 MB / 0.5606 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.0007825/0.3775, allocations: 232.5 kB / 0.7839 GB, free: 12.17 MB / 0.5606 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0001142/0.3776, allocations: 27.98 kB / 0.7839 GB, free: 12.14 MB / 0.5606 GB
Notification: Performance of sorting global known variables: time 0.0008829/0.3785, allocations: 0.5969 MB / 0.7845 GB, free: 11.54 MB / 0.5606 GB
Notification: Performance of sort global known variables: time 9e-08/0.3785, allocations: 0 / 0.7845 GB, free: 11.54 MB / 0.5606 GB
Notification: Performance of remove unused functions: time 0.001418/0.3799, allocations: 435.6 kB / 0.7849 GB, free: 11.11 MB / 0.5606 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 1
 * Number of states: 2 (order2_Inputs_Outputs1.delta,order2_Inputs_Outputs1.w)
 * 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 (63):
 * Single equations (assignments): 62
 * Array equations: 0
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 1
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 0 systems
 * Non-linear torn systems (#iteration vars, #inner vars): 1 system
   {(26,10)}
Notification: Performance of Backend phase and start with SimCode phase: time 0.01653/0.3964, allocations: 5.519 MB / 0.7903 GB, free: 5.555 MB / 0.5606 GB
Notification: Performance of simCode: created initialization part: time 0.007812/0.4043, allocations: 2.374 MB / 0.7926 GB, free: 3.168 MB / 0.5606 GB
Notification: Performance of simCode: created event and clocks part: time 6.262e-06/0.4043, allocations: 0.5625 kB / 0.7926 GB, free: 3.168 MB / 0.5606 GB
Notification: Performance of simCode: created simulation system equations: time 0.005203/0.4095, allocations: 1.514 MB / 0.7941 GB, free: 1.641 MB / 0.5606 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.00107/0.4105, allocations: 88.42 kB / 0.7942 GB, free: 1.551 MB / 0.5606 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.03976/0.4503, allocations: 15.14 MB / 0.809 GB, free: 2.207 MB / 0.5762 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.0007626/0.4511, allocations: 1.088 MB / 0.81 GB, free: 1.094 MB / 0.5762 GB
Notification: Performance of simCode: alias equations: time 0.0004448/0.4515, allocations: 86.75 kB / 0.8101 GB, free: 1.004 MB / 0.5762 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.0006241/0.4521, allocations: 451.3 kB / 0.8105 GB, free: 0.5625 MB / 0.5762 GB
Notification: Performance of SimCode: time 8.32e-07/0.4521, allocations: 0 / 0.8105 GB, free: 0.5625 MB / 0.5762 GB
Notification: Performance of buildModelFMU: Generate the FMI files: time 0.3594/0.8116, allocations: 34.63 MB / 0.8444 GB, free: 87.82 MB / 0.5762 GB
Notification: Performance of buildModelFMU: Generate platform static: time 17.71/18.52, allocations: 9.047 kB / 0.8444 GB, free: 87.82 MB / 0.5762 GB
"
[Timeout remaining time 641]
(rm -f OpenIPSL_dev_OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation.pipe ; mkfifo OpenIPSL_dev_OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation.pipe ; head -c 1048576 < OpenIPSL_dev_OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation.pipe >> ../files/OpenIPSL_dev_OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation.sim & /home/hudson/saved_omc/OMSimulator/install/bin/OMSimulator  --tempDir=temp_OpenIPSL_dev_OpenIPSL_Tests_Machines_PSAT_Order2test2_perturbation_fmu --startTime=0 --stopTime=20 --stepSize=0.008 --timeout=50 --tolerance=1e-06 OpenIPSL_dev_OpenIPSL_Tests_Machines_PSAT_Order2test2_perturbation.fmu > OpenIPSL_dev_OpenIPSL.Tests.Machines.PSAT.Order2test2_perturbation.pipe 2>&1) [Timeout 52.5]
[Calling sys.exit(0), Time elapsed: 22.25818723393604]
Failed to read output from testmodel.py, exit status != 0:
18.703140250989236 18.724387975 18.547493511
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7f9cd51e33a0>