Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC.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.001526/0.001526, allocations: 80.36 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.432/1.432, allocations: 177.1 MB / 199.4 MB, free: 8.441 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.001876/0.001876, allocations: 154.9 kB / 256 MB, free: 4.363 MB / 238.1 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.7112/0.7112, allocations: 80.24 MB / 392.6 MB, free: 13.64 MB / 318.1 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.Tests.Controls.PSSE.COMP.IEEEVC,tolerance=1e-06,outputFormat="empty",numberOfIntervals=100000,variableFilter="",fileNamePrefix="OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC")
translateModel(OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC,tolerance=1e-06,outputFormat="empty",numberOfIntervals=100000,variableFilter="",fileNamePrefix="OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 2.595e-06/2.595e-06, allocations: 0 / 0.5553 GB, free: 3.84 MB / 414.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 4.518e-05/4.778e-05, allocations: 8.938 kB / 0.5553 GB, free: 3.836 MB / 414.1 MB
Notification: Performance of NFInst.instantiate(OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC): time 0.01034/0.01039, allocations: 7.653 MB / 0.5628 GB, free: 12.62 MB / 430.1 MB
Notification: Performance of NFInst.instExpressions: time 0.006926/0.01732, allocations: 2.663 MB / 0.5654 GB, free: 9.949 MB / 430.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.001482/0.0188, allocations: 19.94 kB / 0.5654 GB, free: 9.93 MB / 430.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.001122/0.01992, allocations: 345 kB / 0.5657 GB, free: 9.59 MB / 430.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.003372/0.02329, allocations: 1.083 MB / 0.5668 GB, free: 8.5 MB / 430.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.00262/0.02591, allocations: 0.974 MB / 0.5677 GB, free: 7.535 MB / 430.1 MB
Notification: Performance of NFFlatten.flatten: time 0.003634/0.02954, allocations: 2.368 MB / 0.57 GB, free: 5.156 MB / 430.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.0007139/0.03026, allocations: 338.8 kB / 0.5704 GB, free: 4.793 MB / 430.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.002246/0.0325, allocations: 1.337 MB / 0.5717 GB, free: 3.453 MB / 430.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.001457/0.03396, allocations: 0.9307 MB / 0.5726 GB, free: 2.52 MB / 430.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.000363/0.03432, allocations: 203.9 kB / 0.5728 GB, free: 2.32 MB / 430.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.000905/0.03523, allocations: 407.7 kB / 0.5732 GB, free: 1.922 MB / 430.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.0005043/0.03573, allocations: 498 kB / 0.5736 GB, free: 1.434 MB / 430.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.0008408/0.03657, allocations: 0.6581 MB / 0.5743 GB, free: 0.7734 MB / 430.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.00345/0.04003, allocations: 2.624 MB / 0.5769 GB, free: 14.14 MB / 446.1 MB
Notification: Performance of FrontEnd - DAE generated: time 5.14e-06/0.04003, allocations: 0 / 0.5769 GB, free: 14.14 MB / 446.1 MB
Notification: Performance of FrontEnd: time 1.683e-06/0.04003, allocations: 0 / 0.5769 GB, free: 14.14 MB / 446.1 MB
Notification: Performance of Transformations before backend: time 5.882e-05/0.04009, allocations: 0 / 0.5769 GB, free: 14.14 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: 273
 * Number of variables: 273
Notification: Performance of Generate backend data structure: time 0.01507/0.05516, allocations: 3.972 MB / 0.5807 GB, free: 10.12 MB / 446.1 MB
Notification: Performance of prepare preOptimizeDAE: time 4.327e-05/0.0552, allocations: 8.031 kB / 0.5807 GB, free: 10.11 MB / 446.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.005387/0.06059, allocations: 0.83 MB / 0.5815 GB, free: 9.277 MB / 446.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.002427/0.06302, allocations: 1.117 MB / 0.5826 GB, free: 8.129 MB / 446.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0006766/0.06369, allocations: 0.6352 MB / 0.5833 GB, free: 7.375 MB / 446.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0002672/0.06396, allocations: 124 kB / 0.5834 GB, free: 7.254 MB / 446.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.003587/0.06755, allocations: 1.548 MB / 0.5849 GB, free: 5.656 MB / 446.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 2.598e-05/0.06757, allocations: 0 / 0.5849 GB, free: 5.656 MB / 446.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0001501/0.06772, allocations: 47.94 kB / 0.5849 GB, free: 5.609 MB / 446.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 2.514e-05/0.06775, allocations: 28 kB / 0.585 GB, free: 5.582 MB / 446.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.003648/0.0714, allocations: 1.429 MB / 0.5864 GB, free: 4.145 MB / 446.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.01043/0.08183, allocations: 4.176 MB / 0.5904 GB, free: 15.87 MB / 462.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.009521/0.09135, allocations: 2.469 MB / 0.5928 GB, free: 13.38 MB / 462.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.002676/0.09402, allocations: 0.8722 MB / 0.5937 GB, free: 12.5 MB / 462.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.0003519/0.09438, allocations: 56.95 kB / 0.5938 GB, free: 12.45 MB / 462.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 0.002757/0.09713, allocations: 1.11 MB / 0.5948 GB, free: 11.31 MB / 462.1 MB
Notification: Performance of pre-optimization done (n=130): time 3.677e-06/0.09714, allocations: 0 / 0.5948 GB, free: 11.31 MB / 462.1 MB
Notification: Performance of matching and sorting (n=130): time 0.04668/0.1438, allocations: 10.01 MB / 0.6046 GB, free: 1.281 MB / 462.1 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 9.775e-05/0.1439, allocations: 116.1 kB / 0.6047 GB, free: 1.145 MB / 462.1 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.002493/0.1464, allocations: 1.414 MB / 0.6061 GB, free: 15.72 MB / 478.1 MB
Notification: Performance of collectPreVariables (initialization): time 0.0003749/0.1468, allocations: 53.7 kB / 0.6062 GB, free: 15.66 MB / 478.1 MB
Notification: Performance of collectInitialEqns (initialization): time 0.0006052/0.1474, allocations: 0.6753 MB / 0.6068 GB, free: 14.98 MB / 478.1 MB
Notification: Performance of collectInitialBindings (initialization): time 0.0006552/0.148, allocations: 487.8 kB / 0.6073 GB, free: 14.5 MB / 478.1 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.0007066/0.1488, allocations: 347.5 kB / 0.6076 GB, free: 14.15 MB / 478.1 MB
Notification: Performance of setup shared object (initialization): time 0.0001448/0.1489, allocations: 301.1 kB / 0.6079 GB, free: 13.86 MB / 478.1 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.0025/0.1514, allocations: 1.011 MB / 0.6089 GB, free: 12.84 MB / 478.1 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.002688/0.1541, allocations: 1.243 MB / 0.6101 GB, free: 11.55 MB / 478.1 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.005147/0.1592, allocations: 2.189 MB / 0.6122 GB, free: 9.301 MB / 478.1 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 1.213e-05/0.1592, allocations: 4 kB / 0.6122 GB, free: 9.297 MB / 478.1 MB
Notification: Performance of matching and sorting (n=246) (initialization): time 0.01145/0.1707, allocations: 3.867 MB / 0.616 GB, free: 5.414 MB / 478.1 MB
Notification: Performance of prepare postOptimizeDAE: time 2.923e-05/0.1707, allocations: 10.5 kB / 0.616 GB, free: 5.406 MB / 478.1 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 2.804e-05/0.1708, allocations: 4 kB / 0.616 GB, free: 5.402 MB / 478.1 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.009646/0.1804, allocations: 2.43 MB / 0.6184 GB, free: 2.969 MB / 478.1 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.001836/0.1822, allocations: 335.5 kB / 0.6187 GB, free: 2.641 MB / 478.1 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.007078/0.1893, allocations: 2.627 MB / 0.6213 GB, free: 15.98 MB / 494.1 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.00257/0.1919, allocations: 274.5 kB / 0.6216 GB, free: 15.72 MB / 494.1 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0002252/0.1921, allocations: 67.98 kB / 0.6216 GB, free: 15.65 MB / 494.1 MB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 18
 * Number of states: 0 ()
 * Number of discrete variables: 3 ($whenCondition2,$whenCondition1,eSDC1A.rotatingExciterLimited.sISO.local_reset)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (192):
 * Single equations (assignments): 190
 * Array equations: 0
 * Algorithm blocks: 0
 * Record equations: 1
 * 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
   {(28,25)}
Notification: Performance of prepare postOptimizeDAE: time 0.0007536/0.1929, allocations: 322.4 kB / 0.6219 GB, free: 15.33 MB / 494.1 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0003498/0.1932, allocations: 174.9 kB / 0.6221 GB, free: 15.16 MB / 494.1 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.01818/0.2114, allocations: 4.855 MB / 0.6268 GB, free: 10.29 MB / 494.1 MB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 2.305e-05/0.2114, allocations: 12 kB / 0.6268 GB, free: 10.27 MB / 494.1 MB
Notification: Performance of postOpt constantLinearSystem (simulation): time 8.857e-06/0.2114, allocations: 3.938 kB / 0.6268 GB, free: 10.27 MB / 494.1 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 3.972e-05/0.2115, allocations: 15.91 kB / 0.6269 GB, free: 10.25 MB / 494.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 postOpt removeSimpleEquations (simulation): time 0.02098/0.2324, allocations: 6.207 MB / 0.6329 GB, free: 3.992 MB / 494.1 MB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 1.63e-05/0.2325, allocations: 4 kB / 0.6329 GB, free: 3.988 MB / 494.1 MB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.001165/0.2336, allocations: 159.8 kB / 0.6331 GB, free: 3.832 MB / 494.1 MB
Notification: Performance of postOpt tearingSystem (simulation): time 0.00864/0.2423, allocations: 2.202 MB / 0.6352 GB, free: 1.621 MB / 494.1 MB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0002272/0.2425, allocations: 24 kB / 0.6353 GB, free: 1.598 MB / 494.1 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.02874/0.2712, allocations: 9.831 MB / 0.6449 GB, free: 7.66 MB / 0.4981 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 4.689e-06/0.2712, allocations: 3.938 kB / 0.6449 GB, free: 7.656 MB / 0.4981 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.02106/0.2923, allocations: 6.063 MB / 0.6508 GB, free: 1.559 MB / 0.4981 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.000582/0.2929, allocations: 206.5 kB / 0.651 GB, free: 1.355 MB / 0.4981 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.0003021/0.2932, allocations: 28 kB / 0.651 GB, free: 1.328 MB / 0.4981 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.001678/0.2949, allocations: 143.8 kB / 0.6511 GB, free: 1.188 MB / 0.4981 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.0009676/0.2958, allocations: 285.2 kB / 0.6514 GB, free: 0.9023 MB / 0.4981 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0001205/0.296, allocations: 39.92 kB / 0.6514 GB, free: 0.8633 MB / 0.4981 GB
Notification: Performance of sorting global known variables: time 0.001547/0.2975, allocations: 0.9364 MB / 0.6524 GB, free: 15.93 MB / 0.5137 GB
Notification: Performance of sort global known variables: time 1.4e-07/0.2975, allocations: 4 kB / 0.6524 GB, free: 15.93 MB / 0.5137 GB
Notification: Performance of remove unused functions: time 0.001598/0.2991, allocations: 0.558 MB / 0.6529 GB, free: 15.37 MB / 0.5137 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 3
 * Number of states: 13 (gENCLS.omega,gENCLS.delta,gENCLS.eq,gENSAL.w,gENSAL.delta,gENSAL.Epq,gENSAL.PSIkd,gENSAL.PSIppq,eSDC1A.imDerivativeLag.x,eSDC1A.imLeadLag.TF.x_scaled[1],eSDC1A.simpleLagLim.state,eSDC1A.rotatingExciterLimited.sISO.y,eSDC1A.TransducerDelay.state)
 * Number of discrete variables: 2 ($whenCondition1,$whenCondition2)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for simulation (87):
 * Single equations (assignments): 86
 * 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,23)}
Notification: Performance of Backend phase and start with SimCode phase: time 0.0004104/0.2995, allocations: 171 kB / 0.6531 GB, free: 15.19 MB / 0.5137 GB
Notification: Performance of simCode: created initialization part: time 0.009817/0.3093, allocations: 2.804 MB / 0.6558 GB, free: 12.39 MB / 0.5137 GB
Notification: Performance of simCode: created event and clocks part: time 4.478e-06/0.3093, allocations: 8.125 kB / 0.6558 GB, free: 12.38 MB / 0.5137 GB
Notification: Performance of simCode: created simulation system equations: time 0.007584/0.3169, allocations: 1.923 MB / 0.6577 GB, free: 10.44 MB / 0.5137 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.001376/0.3183, allocations: 149.4 kB / 0.6578 GB, free: 10.29 MB / 0.5137 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.006412/0.3247, allocations: 3.11 MB / 0.6609 GB, free: 7.16 MB / 0.5137 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.0007694/0.3255, allocations: 0.6961 MB / 0.6616 GB, free: 6.426 MB / 0.5137 GB
Notification: Performance of simCode: alias equations: time 0.0005733/0.326, allocations: 150.4 kB / 0.6617 GB, free: 6.277 MB / 0.5137 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.0003912/0.3264, allocations: 104.5 kB / 0.6618 GB, free: 6.172 MB / 0.5137 GB
Notification: Performance of SimCode: time 8.61e-07/0.3264, allocations: 0 / 0.6618 GB, free: 6.172 MB / 0.5137 GB
Notification: Performance of Templates: time 0.05097/0.3774, allocations: 30.78 MB / 0.6919 GB, free: 7.461 MB / 0.545 GB
"
[Timeout remaining time 660]
make -j1 -f OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC.makefile [Timeout 660]
(rm -f OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC.pipe ; mkfifo OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC.pipe ; head -c 1048576 < OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC.pipe >> ../files/OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC.sim & ./OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC  -abortSlowSimulation -alarm=480 -lv LOG_STATS > OpenIPSL_OpenIPSL.Tests.Controls.PSSE.COMP.IEEEVC.pipe 2>&1) [Timeout 480]
[Calling sys.exit(0), Time elapsed: 10.861432004719973]
Failed to read output from testmodel.py, exit status != 0:
0.38719672709703445 0.7085478829999999 0.663349055
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7f32c8ae51e0>