Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE.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.001564/0.001564, allocations: 80.2 kB / 19.18 MB, free: 2.527 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.336/1.336, allocations: 177.2 MB / 199.4 MB, free: 8.453 MB / 190.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.001491/0.001491, allocations: 160.7 kB / 256 MB, free: 4.316 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.5518/0.5518, allocations: 80.36 MB / 392.7 MB, free: 29.64 MB / 334.1 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.TwoAreas.Two_Areas_PSSE,tolerance=0.001,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE")
translateModel(OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE,tolerance=0.001,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 1.263e-06/1.263e-06, allocations: 0 / 0.5554 GB, free: 14.19 MB / 430.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 2.15e-05/2.276e-05, allocations: 10.52 kB / 0.5554 GB, free: 14.18 MB / 430.1 MB
Notification: Performance of NFInst.instantiate(OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE): time 0.01017/0.01019, allocations: 12.8 MB / 0.5679 GB, free: 5.375 MB / 430.1 MB
Notification: Performance of NFInst.instExpressions: time 0.008227/0.01842, allocations: 4.487 MB / 0.5723 GB, free: 1.668 MB / 430.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003083/0.0215, allocations: 28.69 kB / 0.5723 GB, free: 1.668 MB / 430.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.002503/0.02401, allocations: 0.7789 MB / 0.5731 GB, free: 1.07 MB / 430.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.00629/0.0303, allocations: 2.062 MB / 0.5751 GB, free: 15.34 MB / 446.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.003708/0.03401, allocations: 1.433 MB / 0.5765 GB, free: 14.28 MB / 446.1 MB
Notification: Performance of NFFlatten.flatten: time 0.006965/0.04097, allocations: 4.662 MB / 0.5811 GB, free: 11.32 MB / 446.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.001332/0.0423, allocations: 0.5047 MB / 0.5816 GB, free: 10.99 MB / 446.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.005225/0.04753, allocations: 2.592 MB / 0.5841 GB, free: 8.777 MB / 446.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.003355/0.05088, allocations: 1.92 MB / 0.586 GB, free: 6.852 MB / 446.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.0007548/0.05164, allocations: 408 kB / 0.5864 GB, free: 6.453 MB / 446.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.001431/0.05307, allocations: 0.6051 MB / 0.587 GB, free: 5.848 MB / 446.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.0008956/0.05396, allocations: 0.9609 MB / 0.5879 GB, free: 4.883 MB / 446.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.001705/0.05567, allocations: 1.343 MB / 0.5892 GB, free: 3.535 MB / 446.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.006394/0.06206, allocations: 5.428 MB / 0.5945 GB, free: 14.09 MB / 462.1 MB
Notification: Performance of FrontEnd - DAE generated: time 5.2e-06/0.06207, allocations: 3.938 kB / 0.5945 GB, free: 14.09 MB / 462.1 MB
Notification: Performance of FrontEnd: time 2.054e-06/0.06207, allocations: 0 / 0.5945 GB, free: 14.09 MB / 462.1 MB
Notification: Performance of Transformations before backend: time 9.591e-05/0.06217, allocations: 0 / 0.5945 GB, free: 14.09 MB / 462.1 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 497
 * Number of variables: 497
Notification: Performance of Generate backend data structure: time 0.03254/0.0947, allocations: 8.187 MB / 0.6025 GB, free: 5.844 MB / 462.1 MB
Notification: Performance of prepare preOptimizeDAE: time 4.486e-05/0.09475, allocations: 8.031 kB / 0.6025 GB, free: 5.836 MB / 462.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.01142/0.1062, allocations: 1.773 MB / 0.6042 GB, free: 4.059 MB / 462.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.00417/0.1103, allocations: 2.109 MB / 0.6063 GB, free: 1.898 MB / 462.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0008885/0.1112, allocations: 0.8169 MB / 0.6071 GB, free: 0.9492 MB / 462.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0005738/0.1118, allocations: 244 kB / 0.6073 GB, free: 0.7109 MB / 462.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.006213/0.118, allocations: 2.694 MB / 0.61 GB, free: 14.01 MB / 478.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 3.727e-05/0.1181, allocations: 4 kB / 0.61 GB, free: 14 MB / 478.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0002555/0.1183, allocations: 83.94 kB / 0.61 GB, free: 13.92 MB / 478.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 3.937e-05/0.1183, allocations: 48 kB / 0.6101 GB, free: 13.88 MB / 478.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.006725/0.1251, allocations: 2.826 MB / 0.6129 GB, free: 11.05 MB / 478.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.01925/0.1443, allocations: 7.745 MB / 0.6204 GB, free: 3.184 MB / 478.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.01262/0.1569, allocations: 3.886 MB / 0.6242 GB, free: 15.31 MB / 494.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.004409/0.1614, allocations: 1.743 MB / 0.6259 GB, free: 13.56 MB / 494.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.000245/0.1616, allocations: 37.98 kB / 0.626 GB, free: 13.52 MB / 494.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 4.931e-05/0.1616, allocations: 56.56 kB / 0.626 GB, free: 13.46 MB / 494.1 MB
Notification: Performance of pre-optimization done (n=253): time 5.109e-06/0.1617, allocations: 0 / 0.626 GB, free: 13.46 MB / 494.1 MB
Notification: Performance of matching and sorting (n=253): time 0.1158/0.2775, allocations: 25.34 MB / 0.6508 GB, free: 4.066 MB / 0.4981 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 7.546e-05/0.2776, allocations: 77.41 kB / 0.6508 GB, free: 3.98 MB / 0.4981 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.004138/0.2817, allocations: 2.852 MB / 0.6536 GB, free: 1.125 MB / 0.4981 GB
Notification: Performance of collectPreVariables (initialization): time 0.0007285/0.2824, allocations: 85.7 kB / 0.6537 GB, free: 1.035 MB / 0.4981 GB
Notification: Performance of collectInitialEqns (initialization): time 0.001152/0.2836, allocations: 1.282 MB / 0.6549 GB, free: 15.74 MB / 0.5137 GB
Notification: Performance of collectInitialBindings (initialization): time 0.001273/0.2849, allocations: 0.9489 MB / 0.6559 GB, free: 14.78 MB / 0.5137 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.00138/0.2862, allocations: 0.7131 MB / 0.6566 GB, free: 14.05 MB / 0.5137 GB
Notification: Performance of setup shared object (initialization): time 0.0001212/0.2864, allocations: 301.1 kB / 0.6569 GB, free: 13.76 MB / 0.5137 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.005203/0.2916, allocations: 2.265 MB / 0.6591 GB, free: 11.48 MB / 0.5137 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.005834/0.2974, allocations: 2.652 MB / 0.6617 GB, free: 8.738 MB / 0.5137 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.01088/0.3083, allocations: 4.829 MB / 0.6664 GB, free: 3.828 MB / 0.5137 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 1.09e-05/0.3083, allocations: 0 / 0.6664 GB, free: 3.828 MB / 0.5137 GB
Notification: Performance of matching and sorting (n=519) (initialization): time 0.01683/0.3251, allocations: 7.064 MB / 0.6733 GB, free: 12.76 MB / 0.5294 GB
Notification: Performance of prepare postOptimizeDAE: time 2.771e-05/0.3252, allocations: 8 kB / 0.6733 GB, free: 12.75 MB / 0.5294 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 1.955e-05/0.3252, allocations: 4 kB / 0.6733 GB, free: 12.75 MB / 0.5294 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.02133/0.3465, allocations: 5.741 MB / 0.6789 GB, free: 6.996 MB / 0.5294 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.003429/0.3499, allocations: 0.6475 MB / 0.6795 GB, free: 6.348 MB / 0.5294 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.01473/0.3647, allocations: 5.446 MB / 0.6848 GB, free: 0.8789 MB / 0.5294 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.004688/0.3693, allocations: 0.5051 MB / 0.6853 GB, free: 380 kB / 0.5294 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0004307/0.3698, allocations: 135.9 kB / 0.6855 GB, free: 244 kB / 0.5294 GB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 23
 * 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 (398):
 * Single equations (assignments): 397
 * 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
   {(62,60)}
Notification: Performance of prepare postOptimizeDAE: time 0.00127/0.371, allocations: 0.5285 MB / 0.686 GB, free: 15.7 MB / 0.545 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.000699/0.3717, allocations: 345.7 kB / 0.6863 GB, free: 15.36 MB / 0.545 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.03805/0.4098, allocations: 10.46 MB / 0.6965 GB, free: 4.828 MB / 0.545 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 3.16e-05/0.4098, allocations: 24 kB / 0.6965 GB, free: 4.805 MB / 0.545 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 8.997e-06/0.4098, allocations: 7.938 kB / 0.6965 GB, free: 4.801 MB / 0.545 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 5.444e-05/0.4099, allocations: 11.95 kB / 0.6966 GB, free: 4.789 MB / 0.545 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 postOpt removeSimpleEquations (simulation): time 0.04328/0.4532, allocations: 12.86 MB / 0.7091 GB, free: 7.824 MB / 0.5606 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 1.892e-05/0.4532, allocations: 0 / 0.7091 GB, free: 7.824 MB / 0.5606 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.001693/0.4549, allocations: 267.6 kB / 0.7094 GB, free: 7.562 MB / 0.5606 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.01775/0.4726, allocations: 4.745 MB / 0.714 GB, free: 2.809 MB / 0.5606 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0005321/0.4732, allocations: 56 kB / 0.7141 GB, free: 2.754 MB / 0.5606 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.2544/0.7275, allocations: 20.75 MB / 0.7343 GB, free: 134.4 MB / 0.5606 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 2.875e-06/0.7275, allocations: 0 / 0.7343 GB, free: 134.4 MB / 0.5606 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.03899/0.7665, allocations: 12.81 MB / 0.7468 GB, free: 131 MB / 0.5606 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.001003/0.7675, allocations: 434.1 kB / 0.7472 GB, free: 130.8 MB / 0.5606 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.0007205/0.7682, allocations: 51.36 kB / 0.7473 GB, free: 130.7 MB / 0.5606 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.003028/0.7713, allocations: 247.7 kB / 0.7475 GB, free: 130.7 MB / 0.5606 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.001812/0.7731, allocations: 0.5455 MB / 0.7481 GB, free: 130.6 MB / 0.5606 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0001973/0.7733, allocations: 62.2 kB / 0.7481 GB, free: 130.5 MB / 0.5606 GB
Notification: Performance of sorting global known variables: time 0.002111/0.7754, allocations: 1.842 MB / 0.7499 GB, free: 129.8 MB / 0.5606 GB
Notification: Performance of sort global known variables: time 2.11e-07/0.7754, allocations: 4 kB / 0.7499 GB, free: 129.8 MB / 0.5606 GB
Notification: Performance of remove unused functions: time 0.002804/0.7782, allocations: 1.124 MB / 0.751 GB, free: 129.7 MB / 0.5606 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 1
 * Number of states: 20 (g1.gENSAL.w,g1.gENSAL.delta,g1.gENSAL.Epq,g1.gENSAL.PSIkd,g1.gENSAL.PSIppq,g2.gENSAL.w,g2.gENSAL.delta,g2.gENSAL.Epq,g2.gENSAL.PSIkd,g2.gENSAL.PSIppq,g3.gENSAL.w,g3.gENSAL.delta,g3.gENSAL.Epq,g3.gENSAL.PSIkd,g3.gENSAL.PSIppq,g4.gENSAL.w,g4.gENSAL.delta,g4.gENSAL.Epq,g4.gENSAL.PSIkd,g4.gENSAL.PSIppq)
 * 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 (160):
 * Single equations (assignments): 159
 * 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.0004459/0.7786, allocations: 186.8 kB / 0.7512 GB, free: 129.6 MB / 0.5606 GB
Notification: Performance of simCode: created initialization part: time 0.01542/0.7941, allocations: 5.75 MB / 0.7568 GB, free: 125.9 MB / 0.5606 GB
Notification: Performance of simCode: created event and clocks part: time 4.819e-06/0.7941, allocations: 0 / 0.7568 GB, free: 125.9 MB / 0.5606 GB
Notification: Performance of simCode: created simulation system equations: time 0.01067/0.8047, allocations: 3.607 MB / 0.7603 GB, free: 122.3 MB / 0.5606 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.002214/0.807, allocations: 272.3 kB / 0.7606 GB, free: 122.1 MB / 0.5606 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.008078/0.815, allocations: 5.998 MB / 0.7665 GB, free: 116.1 MB / 0.5606 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.0007712/0.8158, allocations: 1.306 MB / 0.7677 GB, free: 114.7 MB / 0.5606 GB
Notification: Performance of simCode: alias equations: time 0.00109/0.8169, allocations: 288.9 kB / 0.768 GB, free: 114.5 MB / 0.5606 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.0006972/0.8176, allocations: 188.5 kB / 0.7682 GB, free: 114.3 MB / 0.5606 GB
Notification: Performance of SimCode: time 1.473e-06/0.8176, allocations: 0 / 0.7682 GB, free: 114.3 MB / 0.5606 GB
Notification: Performance of Templates: time 0.06915/0.8867, allocations: 62.71 MB / 0.8294 GB, free: 51.69 MB / 0.5606 GB
"
[Timeout remaining time 659]
make -j1 -f OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE.makefile [Timeout 660]
(rm -f OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE.pipe ; mkfifo OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE.pipe ; head -c 1048576 < OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE.pipe >> ../files/OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE.sim & ./OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE  -abortSlowSimulation -alarm=480 -lv LOG_STATS > OpenIPSL_dev_OpenIPSL.Examples.TwoAreas.Two_Areas_PSSE.pipe 2>&1) [Timeout 480]
[Calling sys.exit(0), Time elapsed: 7.825725141912699]
Failed to read output from testmodel.py, exit status != 0:
0.8945180475711823 0.90354585 0.839293886
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7fee8ac691e0>