Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR.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.001424/0.001424, allocations: 73.88 kB / 20.65 MB, free: 3.848 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.9593/0.9593, allocations: 177.1 MB / 201 MB, free: 5.707 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.001444/0.001444, allocations: 152.7 kB / 257.7 MB, free: 12.98 MB / 250.7 MB
"
[Timeout remaining time 180]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/OpenIPSL 3.1.0/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/OpenIPSL 3.1.0/package.mo): time 0.2944/0.2944, allocations: 80.24 MB / 394.5 MB, free: 3.043 MB / 362.7 MB
"
[Timeout remaining time 179]
Using package OpenIPSL with version 3.1.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/OpenIPSL 3.1.0/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.TwoAreas.Two_Areas_PSSE_AVR,tolerance=0.001,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR")
translateModel(OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR,tolerance=0.001,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 1.653e-06/1.653e-06, allocations: 0.5469 kB / 491 MB, free: 62.94 MB / 410.7 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 1.841e-05/2.006e-05, allocations: 4.422 kB / 491 MB, free: 62.93 MB / 410.7 MB
Notification: Performance of NFInst.instantiate(OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR): time 0.01063/0.01065, allocations: 17.58 MB / 0.4967 GB, free: 45.29 MB / 410.7 MB
Notification: Performance of NFInst.instExpressions: time 0.009687/0.02034, allocations: 6.266 MB / 0.5028 GB, free: 39.04 MB / 410.7 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.002513/0.02285, allocations: 49 kB / 0.5028 GB, free: 39 MB / 410.7 MB
Notification: Performance of NFTyping.typeComponents: time 0.001659/0.02451, allocations: 0.9863 MB / 0.5038 GB, free: 38 MB / 410.7 MB
Notification: Performance of NFTyping.typeBindings: time 0.004281/0.02879, allocations: 2.625 MB / 0.5064 GB, free: 35.38 MB / 410.7 MB
Notification: Performance of NFTyping.typeClassSections: time 0.002768/0.03156, allocations: 2.26 MB / 0.5086 GB, free: 33.15 MB / 410.7 MB
Notification: Performance of NFFlatten.flatten: time 0.004246/0.03581, allocations: 6.948 MB / 0.5153 GB, free: 26.18 MB / 410.7 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.0009084/0.03672, allocations: 0.8264 MB / 0.5161 GB, free: 25.3 MB / 410.7 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.002533/0.03925, allocations: 3.849 MB / 0.5199 GB, free: 21.44 MB / 410.7 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.001818/0.04107, allocations: 2.672 MB / 0.5225 GB, free: 18.76 MB / 410.7 MB
Notification: Performance of NFPackage.collectConstants: time 0.0006648/0.04173, allocations: 0.6719 MB / 0.5232 GB, free: 18.09 MB / 410.7 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.0008214/0.04255, allocations: 0.8942 MB / 0.524 GB, free: 17.2 MB / 410.7 MB
Notification: Performance of NFScalarize.scalarize: time 0.0005737/0.04313, allocations: 1.498 MB / 0.5255 GB, free: 15.69 MB / 410.7 MB
Notification: Performance of NFVerifyModel.verify: time 0.001179/0.04431, allocations: 1.936 MB / 0.5274 GB, free: 13.75 MB / 410.7 MB
Notification: Performance of NFConvertDAE.convert: time 0.002843/0.04715, allocations: 4.729 MB / 0.532 GB, free: 9.004 MB / 410.7 MB
Notification: Performance of FrontEnd - DAE generated: time 6.763e-06/0.04716, allocations: 6.719 kB / 0.532 GB, free: 9 MB / 410.7 MB
Notification: Performance of FrontEnd: time 1.603e-06/0.04716, allocations: 4 kB / 0.532 GB, free: 8.996 MB / 410.7 MB
Notification: Performance of Transformations before backend: time 5.97e-05/0.04722, allocations: 0 / 0.532 GB, free: 8.996 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: 695
 * Number of variables: 695
Notification: Performance of Generate backend data structure: time 0.01677/0.06399, allocations: 12.23 MB / 0.544 GB, free: 12.7 MB / 426.7 MB
Notification: Performance of prepare preOptimizeDAE: time 3.451e-05/0.06402, allocations: 8.031 kB / 0.544 GB, free: 12.69 MB / 426.7 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.00587/0.06989, allocations: 2.373 MB / 0.5463 GB, free: 10.31 MB / 426.7 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.003004/0.0729, allocations: 2.935 MB / 0.5492 GB, free: 7.309 MB / 426.7 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.000676/0.07357, allocations: 1.395 MB / 0.5505 GB, free: 5.66 MB / 426.7 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0004137/0.07399, allocations: 335.9 kB / 0.5508 GB, free: 5.332 MB / 426.7 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.002791/0.07678, allocations: 2.283 MB / 0.5531 GB, free: 2.961 MB / 426.7 MB
Notification: Performance of preOpt findStateOrder (simulation): time 3.72e-05/0.07682, allocations: 0 / 0.5531 GB, free: 2.961 MB / 426.7 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0002417/0.07706, allocations: 108 kB / 0.5532 GB, free: 2.855 MB / 426.7 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 3.538e-05/0.07709, allocations: 64 kB / 0.5532 GB, free: 2.793 MB / 426.7 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.002066/0.07916, allocations: 1.302 MB / 0.5545 GB, free: 1.461 MB / 426.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.01183/0.09099, allocations: 10.27 MB / 0.5645 GB, free: 6.992 MB / 442.7 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.008231/0.09922, allocations: 2.93 MB / 0.5674 GB, free: 4.027 MB / 442.7 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.001671/0.1009, allocations: 0.8373 MB / 0.5682 GB, free: 3.164 MB / 442.7 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.0003611/0.1013, allocations: 114.5 kB / 0.5683 GB, free: 3.051 MB / 442.7 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 0.001856/0.1031, allocations: 1.458 MB / 0.5698 GB, free: 1.531 MB / 442.7 MB
Notification: Performance of pre-optimization done (n=333): time 7.824e-06/0.1031, allocations: 0 / 0.5698 GB, free: 1.531 MB / 442.7 MB
Notification: Performance of matching and sorting (n=333): time 0.04776/0.1509, allocations: 18.76 MB / 0.5881 GB, free: 14.69 MB / 474.7 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 9.112e-05/0.151, allocations: 192.8 kB / 0.5883 GB, free: 14.46 MB / 474.7 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.004353/0.1553, allocations: 3.427 MB / 0.5916 GB, free: 11.01 MB / 474.7 MB
Notification: Performance of collectPreVariables (initialization): time 0.001077/0.1564, allocations: 101.7 kB / 0.5917 GB, free: 10.91 MB / 474.7 MB
Notification: Performance of collectInitialEqns (initialization): time 0.001432/0.1578, allocations: 1.917 MB / 0.5936 GB, free: 8.977 MB / 474.7 MB
Notification: Performance of collectInitialBindings (initialization): time 0.002096/0.1599, allocations: 1.274 MB / 0.5948 GB, free: 7.691 MB / 474.7 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.001635/0.1616, allocations: 1.095 MB / 0.5959 GB, free: 6.586 MB / 474.7 MB
Notification: Performance of setup shared object (initialization): time 0.0001114/0.1617, allocations: 484.7 kB / 0.5964 GB, free: 6.109 MB / 474.7 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.002043/0.1637, allocations: 1.139 MB / 0.5975 GB, free: 4.965 MB / 474.7 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.002483/0.1662, allocations: 1.785 MB / 0.5992 GB, free: 3.047 MB / 474.7 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.004791/0.171, allocations: 3.048 MB / 0.6022 GB, free: 15.83 MB / 490.7 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 1.659e-05/0.171, allocations: 0 / 0.6022 GB, free: 15.83 MB / 490.7 MB
Notification: Performance of matching and sorting (n=719) (initialization): time 0.008552/0.1796, allocations: 4.932 MB / 0.607 GB, free: 10.83 MB / 490.7 MB
Notification: Performance of prepare postOptimizeDAE: time 3.129e-05/0.1796, allocations: 8 kB / 0.607 GB, free: 10.82 MB / 490.7 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 3.062e-05/0.1796, allocations: 11.98 kB / 0.607 GB, free: 10.81 MB / 490.7 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.01244/0.1921, allocations: 8.181 MB / 0.615 GB, free: 2.625 MB / 490.7 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.00332/0.1954, allocations: 0.9401 MB / 0.6159 GB, free: 1.684 MB / 490.7 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.2296/0.425, allocations: 3.291 MB / 0.6191 GB, free: 108 MB / 490.7 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.004523/0.4295, allocations: 0.5704 MB / 0.6197 GB, free: 108 MB / 490.7 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0006054/0.4301, allocations: 145.4 kB / 0.6198 GB, free: 108 MB / 490.7 MB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 29
 * Number of states: 0 ()
 * Number of discrete variables: 10 (g2.eSDC1A.rotatingExciterLimited.sISO.local_reset,g4.eSDC1A.rotatingExciterLimited.sISO.local_reset,$whenCondition2,$whenCondition1,$whenCondition4,$whenCondition3,$whenCondition6,$whenCondition5,$whenCondition8,$whenCondition7)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (564):
 * Single equations (assignments): 561
 * Array equations: 0
 * Algorithm blocks: 0
 * Record equations: 2
 * 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
   {(80,72)}
Notification: Performance of prepare postOptimizeDAE: time 0.001461/0.4316, allocations: 393.5 kB / 0.6202 GB, free: 107.9 MB / 490.7 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.001136/0.4327, allocations: 0.5694 MB / 0.6208 GB, free: 107.9 MB / 490.7 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.01359/0.4463, allocations: 7.052 MB / 0.6277 GB, free: 107.6 MB / 490.7 MB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 3.928e-05/0.4463, allocations: 34.72 kB / 0.6277 GB, free: 107.6 MB / 490.7 MB
Notification: Performance of postOpt constantLinearSystem (simulation): time 9.347e-06/0.4463, allocations: 3.25 kB / 0.6277 GB, free: 107.6 MB / 490.7 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 9.107e-05/0.4464, allocations: 23.2 kB / 0.6277 GB, free: 107.6 MB / 490.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 postOpt removeSimpleEquations (simulation): time 0.01998/0.4664, allocations: 10.45 MB / 0.6379 GB, free: 106.6 MB / 490.7 MB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 1.936e-05/0.4664, allocations: 3.844 kB / 0.6379 GB, free: 106.6 MB / 490.7 MB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.001692/0.4681, allocations: 423.4 kB / 0.6383 GB, free: 106.6 MB / 490.7 MB
Notification: Performance of postOpt tearingSystem (simulation): time 0.01305/0.4812, allocations: 4.913 MB / 0.6431 GB, free: 106.3 MB / 490.7 MB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0009301/0.4821, allocations: 82.8 kB / 0.6432 GB, free: 106.3 MB / 490.7 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.01657/0.4987, allocations: 9.898 MB / 0.6529 GB, free: 100 MB / 490.7 MB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 3.406e-06/0.4987, allocations: 4 kB / 0.6529 GB, free: 100 MB / 490.7 MB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.01677/0.5154, allocations: 8.115 MB / 0.6608 GB, free: 92.38 MB / 490.7 MB
Notification: Performance of postOpt removeConstants (simulation): time 0.001698/0.5171, allocations: 0.6076 MB / 0.6614 GB, free: 91.82 MB / 490.7 MB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.001202/0.5183, allocations: 72 kB / 0.6615 GB, free: 91.75 MB / 490.7 MB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.002003/0.5203, allocations: 255.8 kB / 0.6617 GB, free: 91.5 MB / 490.7 MB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.001342/0.5217, allocations: 0.6169 MB / 0.6623 GB, free: 90.89 MB / 490.7 MB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0001874/0.5219, allocations: 67.61 kB / 0.6624 GB, free: 90.82 MB / 490.7 MB
Notification: Performance of sorting global known variables: time 0.00171/0.5236, allocations: 1.912 MB / 0.6642 GB, free: 89.1 MB / 490.7 MB
Notification: Performance of sort global known variables: time 1.81e-07/0.5236, allocations: 0 / 0.6642 GB, free: 89.1 MB / 490.7 MB
Notification: Performance of remove unused functions: time 0.003342/0.5269, allocations: 1.445 MB / 0.6656 GB, free: 87.71 MB / 490.7 MB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 5
 * Number of states: 38 (g1.g1.w,g1.g1.delta,g1.g1.Epd,g1.g1.Epq,g1.g1.PSIkd,g1.g1.PSIkq,g1.sEXS.simpleLagLim.state,g1.sEXS.leadLag.TF.x_scaled[1],g2.g2.w,g2.g2.delta,g2.g2.Epd,g2.g2.Epq,g2.g2.PSIkd,g2.g2.PSIkq,g2.eSDC1A.imDerivativeLag.x,g2.eSDC1A.imLeadLag.TF.x_scaled[1],g2.eSDC1A.simpleLagLim.state,g2.eSDC1A.rotatingExciterLimited.sISO.y,g2.eSDC1A.TransducerDelay.state,g3.g3.w,g3.g3.delta,g3.g3.Epd,g3.g3.Epq,g3.g3.PSIkd,g3.g3.PSIkq,g3.sEXS.simpleLagLim.state,g3.sEXS.leadLag.TF.x_scaled[1],g4.gENSAL.w,g4.gENSAL.delta,g4.gENSAL.Epd,g4.gENSAL.Epq,g4.gENSAL.PSIkd,g4.gENSAL.PSIkq,g4.eSDC1A.imDerivativeLag.x,g4.eSDC1A.imLeadLag.TF.x_scaled[1],g4.eSDC1A.simpleLagLim.state,g4.eSDC1A.rotatingExciterLimited.sISO.y,g4.eSDC1A.TransducerDelay.state)
 * Number of discrete variables: 8 ($whenCondition7,$whenCondition8,$whenCondition5,$whenCondition6,$whenCondition3,$whenCondition4,$whenCondition1,$whenCondition2)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for simulation (240):
 * Single equations (assignments): 239
 * 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
   {(54,52)}
Notification: Performance of Backend phase and start with SimCode phase: time 0.0005136/0.5274, allocations: 241.6 kB / 0.6659 GB, free: 87.5 MB / 490.7 MB
Notification: Performance of simCode: created initialization part: time 0.007731/0.5352, allocations: 4.346 MB / 0.6701 GB, free: 83.24 MB / 490.7 MB
Notification: Performance of simCode: created event and clocks part: time 4.188e-06/0.5352, allocations: 0 / 0.6701 GB, free: 83.24 MB / 490.7 MB
Notification: Performance of simCode: created simulation system equations: time 0.004881/0.5401, allocations: 2.806 MB / 0.6729 GB, free: 80.52 MB / 490.7 MB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.002626/0.5427, allocations: 459.7 kB / 0.6733 GB, free: 80.09 MB / 490.7 MB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.01016/0.5528, allocations: 7.846 MB / 0.681 GB, free: 72.27 MB / 490.7 MB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.0006007/0.5534, allocations: 0.7117 MB / 0.6817 GB, free: 71.53 MB / 490.7 MB
Notification: Performance of simCode: alias equations: time 0.001841/0.5553, allocations: 420.2 kB / 0.6821 GB, free: 71.12 MB / 490.7 MB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001182/0.5565, allocations: 0.5411 MB / 0.6826 GB, free: 70.57 MB / 490.7 MB
Notification: Performance of SimCode: time 2.104e-06/0.5565, allocations: 0 / 0.6826 GB, free: 70.57 MB / 490.7 MB
Notification: Performance of Templates: time 0.09563/0.6521, allocations: 87.48 MB / 0.768 GB, free: 15.49 MB / 0.5105 GB
"
[Timeout remaining time 659]
make -j1 -f OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR.makefile [Timeout 660]
(rm -f OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR.pipe ; mkfifo OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR.pipe ; head -c 1048576 < OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR.pipe >> ../files/OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR.sim & ./OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR -abortSlowSimulation -alarm=240  -lv LOG_STATS > OpenIPSL_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE_AVR.pipe 2>&1) [Timeout 240]
[Calling sys.exit(0), Time elapsed: 6.397734532132745]