Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII.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.001415/0.001415, allocations: 73.88 kB / 20.66 MB, free: 3.844 MB / 18.57 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 0.8906/0.8906, allocations: 177.2 MB / 201 MB, free: 5.719 MB / 186.7 MB
"
[Timeout remaining time 179]
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.001283/0.001283, allocations: 160.6 kB / 257.7 MB, free: 12.99 MB / 250.7 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.2955/0.2955, allocations: 83.27 MB / 397.5 MB, free: 88 kB / 362.7 MB
"
[Timeout remaining time 179]
Using package OpenIPSL with version 3.2.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: translateModel(OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII,tolerance=1e-06,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII")
translateModel(OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII,tolerance=1e-06,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 1.313e-06/1.313e-06, allocations: 0 / 495.2 MB, free: 58.57 MB / 410.7 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 2.264e-05/2.396e-05, allocations: 4.953 kB / 495.2 MB, free: 58.57 MB / 410.7 MB
Notification: Performance of NFInst.instantiate(OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII): time 0.01461/0.01464, allocations: 12.44 MB / 0.4957 GB, free: 46.1 MB / 410.7 MB
Notification: Performance of NFInst.instExpressions: time 0.005672/0.02031, allocations: 3.476 MB / 0.4991 GB, free: 42.64 MB / 410.7 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.001901/0.02221, allocations: 31.94 kB / 0.4991 GB, free: 42.61 MB / 410.7 MB
Notification: Performance of NFTyping.typeComponents: time 0.001373/0.02358, allocations: 0.5614 MB / 0.4997 GB, free: 42.04 MB / 410.7 MB
Notification: Performance of NFTyping.typeBindings: time 0.003882/0.02747, allocations: 1.615 MB / 0.5013 GB, free: 40.43 MB / 410.7 MB
Notification: Performance of NFTyping.typeClassSections: time 0.002804/0.03027, allocations: 1.525 MB / 0.5028 GB, free: 38.95 MB / 410.7 MB
Notification: Performance of NFFlatten.flatten: time 0.004114/0.03438, allocations: 3.735 MB / 0.5064 GB, free: 35.2 MB / 410.7 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.001096/0.03548, allocations: 0.582 MB / 0.507 GB, free: 34.56 MB / 410.7 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.003133/0.03861, allocations: 2.141 MB / 0.5091 GB, free: 32.41 MB / 410.7 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.001279/0.03989, allocations: 1.577 MB / 0.5106 GB, free: 30.83 MB / 410.7 MB
Notification: Performance of NFPackage.collectConstants: time 0.0004079/0.0403, allocations: 284 kB / 0.5109 GB, free: 30.55 MB / 410.7 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.0006582/0.04096, allocations: 447.7 kB / 0.5113 GB, free: 30.12 MB / 410.7 MB
Notification: Performance of NFScalarize.scalarize: time 0.0003415/0.0413, allocations: 0.7816 MB / 0.5121 GB, free: 29.33 MB / 410.7 MB
Notification: Performance of NFVerifyModel.verify: time 0.0008739/0.04217, allocations: 1.082 MB / 0.5131 GB, free: 28.25 MB / 410.7 MB
Notification: Performance of NFConvertDAE.convert: time 0.002162/0.04434, allocations: 2.888 MB / 0.5159 GB, free: 25.35 MB / 410.7 MB
Notification: Performance of FrontEnd - DAE generated: time 4.699e-06/0.04434, allocations: 0 / 0.5159 GB, free: 25.35 MB / 410.7 MB
Notification: Performance of FrontEnd: time 1.272e-06/0.04434, allocations: 0 / 0.5159 GB, free: 25.35 MB / 410.7 MB
Notification: Performance of Transformations before backend: time 3.973e-05/0.04438, allocations: 0 / 0.5159 GB, free: 25.35 MB / 410.7 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 522
 * Number of variables: 522
Notification: Performance of Generate backend data structure: time 0.01146/0.05584, allocations: 7.653 MB / 0.5234 GB, free: 17.63 MB / 410.7 MB
Notification: Performance of prepare preOptimizeDAE: time 3.995e-05/0.05588, allocations: 8.031 kB / 0.5234 GB, free: 17.62 MB / 410.7 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.00762/0.0635, allocations: 2.725 MB / 0.5261 GB, free: 14.89 MB / 410.7 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.002045/0.06555, allocations: 1.695 MB / 0.5277 GB, free: 13.14 MB / 410.7 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0003232/0.06587, allocations: 0.8061 MB / 0.5285 GB, free: 12.19 MB / 410.7 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.000326/0.06619, allocations: 224 kB / 0.5287 GB, free: 11.97 MB / 410.7 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.002026/0.06822, allocations: 1.792 MB / 0.5305 GB, free: 10.09 MB / 410.7 MB
Notification: Performance of preOpt findStateOrder (simulation): time 3.216e-05/0.06825, allocations: 0 / 0.5305 GB, free: 10.09 MB / 410.7 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0001608/0.06841, allocations: 84 kB / 0.5306 GB, free: 10 MB / 410.7 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 2.109e-05/0.06843, allocations: 52 kB / 0.5306 GB, free: 9.953 MB / 410.7 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.001387/0.06982, allocations: 1.046 MB / 0.5316 GB, free: 8.852 MB / 410.7 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.008157/0.07798, allocations: 6.609 MB / 0.5381 GB, free: 2.074 MB / 410.7 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.003172/0.08115, allocations: 1.96 MB / 0.54 GB, free: 80 kB / 410.7 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.0009157/0.08207, allocations: 0.7365 MB / 0.5407 GB, free: 15.33 MB / 426.7 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.0001808/0.08225, allocations: 45.98 kB / 0.5408 GB, free: 15.28 MB / 426.7 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 0.001273/0.08352, allocations: 1.185 MB / 0.5419 GB, free: 14.06 MB / 426.7 MB
Notification: Performance of pre-optimization done (n=247): time 4.298e-06/0.08353, allocations: 0 / 0.5419 GB, free: 14.06 MB / 426.7 MB
Notification: Performance of matching and sorting (n=247): time 0.05407/0.1376, allocations: 21.7 MB / 0.5631 GB, free: 8.27 MB / 442.7 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 7.518e-05/0.1377, allocations: 188.2 kB / 0.5633 GB, free: 8.051 MB / 442.7 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.001748/0.1394, allocations: 1.968 MB / 0.5652 GB, free: 6.07 MB / 442.7 MB
Notification: Performance of collectPreVariables (initialization): time 0.0004491/0.1399, allocations: 69.7 kB / 0.5653 GB, free: 5.996 MB / 442.7 MB
Notification: Performance of collectInitialEqns (initialization): time 0.0006957/0.1406, allocations: 1.293 MB / 0.5666 GB, free: 4.691 MB / 442.7 MB
Notification: Performance of collectInitialBindings (initialization): time 0.0008732/0.1414, allocations: 0.9218 MB / 0.5675 GB, free: 3.762 MB / 442.7 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.0008368/0.1423, allocations: 0.5803 MB / 0.568 GB, free: 3.168 MB / 442.7 MB
Notification: Performance of setup shared object (initialization): time 9.869e-05/0.1424, allocations: 476.8 kB / 0.5685 GB, free: 2.699 MB / 442.7 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.001271/0.1436, allocations: 0.8717 MB / 0.5693 GB, free: 1.801 MB / 442.7 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.00144/0.1451, allocations: 1.343 MB / 0.5706 GB, free: 312 kB / 442.7 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.004106/0.1492, allocations: 3.466 MB / 0.574 GB, free: 12.61 MB / 458.7 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 1.088e-05/0.1492, allocations: 0 / 0.574 GB, free: 12.61 MB / 458.7 MB
Notification: Performance of matching and sorting (n=407) (initialization): time 0.01583/0.165, allocations: 8.247 MB / 0.5821 GB, free: 4.27 MB / 458.7 MB
Notification: Performance of prepare postOptimizeDAE: time 7.713e-05/0.1651, allocations: 110.8 kB / 0.5822 GB, free: 4.137 MB / 458.7 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 1.672e-05/0.1651, allocations: 12 kB / 0.5822 GB, free: 4.125 MB / 458.7 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.01425/0.1794, allocations: 5.364 MB / 0.5874 GB, free: 14.75 MB / 474.7 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.001801/0.1812, allocations: 0.5538 MB / 0.588 GB, free: 14.2 MB / 474.7 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.01787/0.199, allocations: 9.317 MB / 0.5971 GB, free: 4.766 MB / 474.7 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.00239/0.2014, allocations: 402 kB / 0.5975 GB, free: 4.371 MB / 474.7 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0002933/0.2017, allocations: 87.95 kB / 0.5975 GB, free: 4.285 MB / 474.7 MB
Warning: Assuming fixed start value for the following 6 variables:
         order3_2.delta:VARIABLE(flow=false start = order3_2.delta0 unit = \"rad\" fixed = true )  \"Rotor angle\" type: Real
         order3_2.w:VARIABLE(flow=false start = 1.0 fixed = true )  \"Rotor speed [pu]\" type: Real
         order3_2.e1q:VARIABLE(start = order3_2.e1q0 unit = \"1\" fixed = true )  \"q-axis transient voltage\" type: Real
         order2.delta:VARIABLE(flow=false start = order2.delta0 unit = \"rad\" fixed = true )  \"Rotor angle\" type: Real
         order2.w:VARIABLE(flow=false start = 1.0 fixed = true )  \"Rotor speed [pu]\" type: Real
         order3_1.w:VARIABLE(flow=false start = 1.0 fixed = true )  \"Rotor speed [pu]\" type: Real
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 29
 * Number of states: 0 ()
 * Number of discrete variables: 4 ($whenCondition2,$whenCondition1,$whenCondition4,$whenCondition3)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (319):
 * Single equations (assignments): 314
 * Array equations: 0
 * Algorithm blocks: 4
 * 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
   {(63,26)}
Notification: Performance of prepare postOptimizeDAE: time 0.0008406/0.2026, allocations: 384.3 kB / 0.5979 GB, free: 3.891 MB / 474.7 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0006175/0.2032, allocations: 386 kB / 0.5983 GB, free: 3.512 MB / 474.7 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.01512/0.2183, allocations: 7.452 MB / 0.6055 GB, free: 12 MB / 490.7 MB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 2.359e-05/0.2183, allocations: 31.88 kB / 0.6056 GB, free: 11.96 MB / 490.7 MB
Notification: Performance of postOpt constantLinearSystem (simulation): time 2.563e-05/0.2184, allocations: 24 kB / 0.6056 GB, free: 11.94 MB / 490.7 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 5.185e-05/0.2184, allocations: 15.94 kB / 0.6056 GB, free: 11.93 MB / 490.7 MB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.01853/0.2369, allocations: 9.503 MB / 0.6149 GB, free: 2.328 MB / 490.7 MB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 1.32e-05/0.237, allocations: 64 / 0.6149 GB, free: 2.328 MB / 490.7 MB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.0009802/0.2379, allocations: 247.7 kB / 0.6151 GB, free: 2.086 MB / 490.7 MB
Notification: Performance of postOpt tearingSystem (simulation): time 0.1691/0.407, allocations: 5.238 MB / 0.6202 GB, free: 124.8 MB / 490.7 MB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0005128/0.4075, allocations: 54.95 kB / 0.6203 GB, free: 124.8 MB / 490.7 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.01692/0.4245, allocations: 13.02 MB / 0.633 GB, free: 119.1 MB / 490.7 MB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 1.523e-06/0.4245, allocations: 0 / 0.633 GB, free: 119.1 MB / 490.7 MB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.01571/0.4402, allocations: 8.241 MB / 0.6411 GB, free: 118.3 MB / 490.7 MB
Notification: Performance of postOpt removeConstants (simulation): time 0.0006167/0.4408, allocations: 348.8 kB / 0.6414 GB, free: 118.1 MB / 490.7 MB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.0003265/0.4411, allocations: 41.03 kB / 0.6414 GB, free: 118.1 MB / 490.7 MB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.001254/0.4424, allocations: 215.3 kB / 0.6416 GB, free: 118.1 MB / 490.7 MB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.001152/0.4435, allocations: 0.5733 MB / 0.6422 GB, free: 117.9 MB / 490.7 MB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0001305/0.4436, allocations: 49.52 kB / 0.6422 GB, free: 117.9 MB / 490.7 MB
Notification: Performance of sorting global known variables: time 0.000744/0.4444, allocations: 1.116 MB / 0.6433 GB, free: 117.7 MB / 490.7 MB
Notification: Performance of sort global known variables: time 1.7e-07/0.4444, allocations: 7.812 kB / 0.6433 GB, free: 117.7 MB / 490.7 MB
Notification: Performance of remove unused functions: time 0.002115/0.4465, allocations: 1.163 MB / 0.6445 GB, free: 117.5 MB / 490.7 MB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 3
 * Number of states: 16 (order3_2.delta,order3_2.w,order3_2.e1q,order2.delta,order2.w,order3_1.delta,order3_1.w,order3_1.e1q,Exc1.ExcitationSystem.x_scaled[1],Exc1.derivativeBlock.x,Exc1.firstOrder2.y,Exc1.simpleLagLim.state,Exc2.ExcitationSystem.x_scaled[1],Exc2.derivativeBlock.x,Exc2.firstOrder2.y,Exc2.simpleLagLim.state)
 * Number of discrete variables: 4 ($whenCondition3,$whenCondition4,$whenCondition1,$whenCondition2)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for simulation (156):
 * Single equations (assignments): 151
 * Array equations: 0
 * Algorithm blocks: 2
 * 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
   {(66,22,7.7%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 2 systems
   {(1,6), (1,6)}
Notification: Performance of Backend phase and start with SimCode phase: time 0.0003491/0.4469, allocations: 176.2 kB / 0.6446 GB, free: 117.4 MB / 490.7 MB
Notification: Performance of simCode: created initialization part: time 0.006459/0.4533, allocations: 4.264 MB / 0.6488 GB, free: 114.4 MB / 490.7 MB
Notification: Performance of simCode: created event and clocks part: time 8.455e-06/0.4533, allocations: 4 kB / 0.6488 GB, free: 114.4 MB / 490.7 MB
Notification: Performance of simCode: created simulation system equations: time 0.004941/0.4583, allocations: 3.156 MB / 0.6519 GB, free: 111.7 MB / 490.7 MB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.001384/0.4596, allocations: 326.8 kB / 0.6522 GB, free: 111.5 MB / 490.7 MB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.00601/0.4657, allocations: 4.852 MB / 0.6569 GB, free: 107.1 MB / 490.7 MB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.0004208/0.4661, allocations: 0.5368 MB / 0.6575 GB, free: 106.6 MB / 490.7 MB
Notification: Performance of simCode: alias equations: time 0.0007223/0.4668, allocations: 258.7 kB / 0.6577 GB, free: 106.5 MB / 490.7 MB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.0006016/0.4674, allocations: 377.1 kB / 0.6581 GB, free: 106.1 MB / 490.7 MB
Notification: Performance of SimCode: time 1.553e-06/0.4674, allocations: 0 / 0.6581 GB, free: 106.1 MB / 490.7 MB
Notification: Performance of Templates: time 0.06913/0.5365, allocations: 78.21 MB / 0.7345 GB, free: 29.14 MB / 490.7 MB
"
[Timeout remaining time 659]
make -j1 -f OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII.makefile [Timeout 660]
(rm -f OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII.pipe ; mkfifo OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII.pipe ; head -c 1048576 < OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII.pipe >> ../files/OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII.sim & ./OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII -abortSlowSimulation -alarm=240  -lv LOG_STATS > OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.ThreeArea.ThirdOrder_AVRII.pipe 2>&1) [Timeout 240]
[Calling sys.exit(0), Time elapsed: 5.404242787975818]