Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.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.0008933/0.0008933, allocations: 76.55 kB / 19.93 MB, free: 4.633 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.8923/0.8923, allocations: 177.2 MB / 200.2 MB, free: 5.957 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.001156/0.001156, allocations: 159.4 kB / 256.7 MB, free: 13.37 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.2634/0.2634, allocations: 80.37 MB / 393.5 MB, free: 2.375 MB / 314.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.TwoArea.ThirdOrder_AVRII,tolerance=1e-06,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII")
translateModel(OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII,tolerance=1e-06,outputFormat="empty",numberOfIntervals=2500,variableFilter="",fileNamePrefix="OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 2.033e-06/2.033e-06, allocations: 0 / 0.5563 GB, free: 11.97 MB / 490.7 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 2.763e-05/2.967e-05, allocations: 13.45 kB / 0.5563 GB, free: 11.96 MB / 490.7 MB
Notification: Performance of NFInst.instantiate(OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII): time 0.01328/0.01331, allocations: 18.39 MB / 0.5743 GB, free: 9.488 MB / 0.4948 GB
Notification: Performance of NFInst.instExpressions: time 0.009974/0.02328, allocations: 4.834 MB / 0.579 GB, free: 4.633 MB / 0.4948 GB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003687/0.02697, allocations: 44 kB / 0.579 GB, free: 4.59 MB / 0.4948 GB
Notification: Performance of NFTyping.typeComponents: time 0.002493/0.02946, allocations: 0.8788 MB / 0.5799 GB, free: 3.703 MB / 0.4948 GB
Notification: Performance of NFTyping.typeBindings: time 0.00623/0.03569, allocations: 2.344 MB / 0.5822 GB, free: 1.348 MB / 0.4948 GB
Notification: Performance of NFTyping.typeClassSections: time 0.003802/0.03949, allocations: 2.079 MB / 0.5842 GB, free: 15.3 MB / 0.5105 GB
Notification: Performance of NFFlatten.flatten: time 0.00701/0.0465, allocations: 5.858 MB / 0.5899 GB, free: 9.41 MB / 0.5105 GB
Notification: Performance of NFFlatten.resolveConnections: time 0.001508/0.04801, allocations: 0.8687 MB / 0.5908 GB, free: 8.488 MB / 0.5105 GB
Notification: Performance of NFEvalConstants.evaluate: time 0.00456/0.05257, allocations: 3.3 MB / 0.594 GB, free: 5.18 MB / 0.5105 GB
Notification: Performance of NFSimplifyModel.simplify: time 0.002545/0.05512, allocations: 2.262 MB / 0.5962 GB, free: 2.91 MB / 0.5105 GB
Notification: Performance of NFPackage.collectConstants: time 0.001117/0.05623, allocations: 436 kB / 0.5966 GB, free: 2.484 MB / 0.5105 GB
Notification: Performance of NFFlatten.collectFunctions: time 0.001055/0.05729, allocations: 0.5974 MB / 0.5972 GB, free: 1.887 MB / 0.5105 GB
Notification: Performance of NFScalarize.scalarize: time 0.0006656/0.05795, allocations: 1.174 MB / 0.5984 GB, free: 0.707 MB / 0.5105 GB
Notification: Performance of NFVerifyModel.verify: time 0.225/0.283, allocations: 1.716 MB / 0.6 GB, free: 64.91 MB / 0.5105 GB
Notification: Performance of NFConvertDAE.convert: time 0.005165/0.2881, allocations: 6.321 MB / 0.6062 GB, free: 64.51 MB / 0.5105 GB
Notification: Performance of FrontEnd - DAE generated: time 6.211e-06/0.2882, allocations: 0 / 0.6062 GB, free: 64.51 MB / 0.5105 GB
Notification: Performance of FrontEnd: time 1.683e-06/0.2882, allocations: 0 / 0.6062 GB, free: 64.51 MB / 0.5105 GB
Notification: Performance of Transformations before backend: time 0.0001806/0.2883, allocations: 0 / 0.6062 GB, free: 64.51 MB / 0.5105 GB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 892
 * Number of variables: 892
Notification: Performance of Generate backend data structure: time 0.01955/0.3079, allocations: 9.847 MB / 0.6158 GB, free: 61.88 MB / 0.5105 GB
Notification: Performance of prepare preOptimizeDAE: time 4.737e-05/0.3079, allocations: 9.422 kB / 0.6158 GB, free: 61.88 MB / 0.5105 GB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.01573/0.3237, allocations: 4.051 MB / 0.6198 GB, free: 61.48 MB / 0.5105 GB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.007781/0.3314, allocations: 2.569 MB / 0.6223 GB, free: 60.63 MB / 0.5105 GB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.000653/0.3321, allocations: 1.031 MB / 0.6233 GB, free: 59.84 MB / 0.5105 GB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0006643/0.3328, allocations: 348.8 kB / 0.6236 GB, free: 59.84 MB / 0.5105 GB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.006779/0.3395, allocations: 4.749 MB / 0.6283 GB, free: 58.48 MB / 0.5105 GB
Notification: Performance of preOpt findStateOrder (simulation): time 4.441e-05/0.3396, allocations: 1.5 kB / 0.6283 GB, free: 58.48 MB / 0.5105 GB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.000286/0.3399, allocations: 143.6 kB / 0.6284 GB, free: 58.37 MB / 0.5105 GB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 6.085e-05/0.3399, allocations: 86.25 kB / 0.6285 GB, free: 58.37 MB / 0.5105 GB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.005882/0.3458, allocations: 4.246 MB / 0.6326 GB, free: 56.88 MB / 0.5105 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.01974/0.3656, allocations: 13.01 MB / 0.6453 GB, free: 49.43 MB / 0.5105 GB
Notification: Performance of preOpt comSubExp (simulation): time 0.006193/0.3718, allocations: 4.352 MB / 0.6496 GB, free: 47.4 MB / 0.5105 GB
Notification: Performance of preOpt resolveLoops (simulation): time 0.003136/0.3749, allocations: 2.5 MB / 0.652 GB, free: 46.11 MB / 0.5105 GB
Notification: Performance of preOpt evalFunc (simulation): time 0.000272/0.3752, allocations: 57.98 kB / 0.6521 GB, free: 46.1 MB / 0.5105 GB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 0.003407/0.3786, allocations: 3.194 MB / 0.6552 GB, free: 44.24 MB / 0.5105 GB
Notification: Performance of pre-optimization done (n=382): time 5.37e-06/0.3786, allocations: 0 / 0.6552 GB, free: 44.24 MB / 0.5105 GB
Notification: Performance of matching and sorting (n=382): time 0.1509/0.5295, allocations: 67.99 MB / 0.7216 GB, free: 9.723 MB / 0.5417 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 8.572e-05/0.5296, allocations: 153.3 kB / 0.7218 GB, free: 9.551 MB / 0.5417 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.003873/0.5335, allocations: 3.209 MB / 0.7249 GB, free: 6.32 MB / 0.5417 GB
Notification: Performance of collectPreVariables (initialization): time 0.001016/0.5345, allocations: 89.7 kB / 0.725 GB, free: 6.227 MB / 0.5417 GB
Notification: Performance of collectInitialEqns (initialization): time 0.001017/0.5355, allocations: 2.003 MB / 0.7269 GB, free: 4.219 MB / 0.5417 GB
Notification: Performance of collectInitialBindings (initialization): time 0.001324/0.5368, allocations: 1.353 MB / 0.7283 GB, free: 2.887 MB / 0.5417 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.000948/0.5378, allocations: 0.6586 MB / 0.7289 GB, free: 2.215 MB / 0.5417 GB
Notification: Performance of setup shared object (initialization): time 7.539e-05/0.5379, allocations: 309.1 kB / 0.7292 GB, free: 1.91 MB / 0.5417 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.003651/0.5415, allocations: 2.619 MB / 0.7317 GB, free: 15.27 MB / 0.5573 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.003697/0.5452, allocations: 3.24 MB / 0.7349 GB, free: 11.8 MB / 0.5573 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.039/0.5842, allocations: 18.94 MB / 0.7534 GB, free: 8.656 MB / 0.573 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 2.454e-05/0.5842, allocations: 7.828 kB / 0.7534 GB, free: 8.652 MB / 0.573 GB
Notification: Performance of matching and sorting (n=527) (initialization): time 0.03205/0.6163, allocations: 16.84 MB / 0.7699 GB, free: 7.957 MB / 0.5886 GB
Notification: Performance of prepare postOptimizeDAE: time 8.007e-05/0.6164, allocations: 71.39 kB / 0.7699 GB, free: 7.875 MB / 0.5886 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 3.534e-05/0.6164, allocations: 16 kB / 0.7699 GB, free: 7.859 MB / 0.5886 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.01412/0.6305, allocations: 7.224 MB / 0.777 GB, free: 0.6328 MB / 0.5886 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.002344/0.6329, allocations: 0.6561 MB / 0.7776 GB, free: 20 kB / 0.5886 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.05369/0.6865, allocations: 32.72 MB / 0.8096 GB, free: 15.25 MB / 0.6355 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.00467/0.6912, allocations: 0.6182 MB / 0.8102 GB, free: 14.63 MB / 0.6355 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0004906/0.6917, allocations: 148 kB / 0.8103 GB, free: 14.48 MB / 0.6355 GB
Warning: Assuming fixed start value for the following 4 variables:
         order3_1.w:VARIABLE(flow=false start = 1.0 fixed = true )  \"Rotor speed [pu]\" type: Real
         order3.w:VARIABLE(flow=false start = 1.0 fixed = true )  \"Rotor speed [pu]\" type: Real
         order3.delta:VARIABLE(flow=false start = order3.delta0 unit = \"rad\" fixed = true )  \"Rotor angle\" type: Real
         order3.e1q:VARIABLE(start = order3.e1q0 unit = \"1\" fixed = true )  \"q-axis transient voltage\" type: Real
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 65
 * Number of states: 0 ()
 * Number of discrete variables: 2 ($whenCondition2,$whenCondition1)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (391):
 * Single equations (assignments): 388
 * Array equations: 0
 * Algorithm blocks: 2
 * 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
   {(92,45)}
Notification: Performance of prepare postOptimizeDAE: time 0.001676/0.6934, allocations: 0.6644 MB / 0.811 GB, free: 13.85 MB / 0.6355 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.001086/0.6945, allocations: 484.8 kB / 0.8114 GB, free: 13.38 MB / 0.6355 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.03033/0.7248, allocations: 16.73 MB / 0.8278 GB, free: 12.68 MB / 0.6511 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 3.229e-05/0.7248, allocations: 43.12 kB / 0.8278 GB, free: 12.64 MB / 0.6511 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 3.087e-05/0.7249, allocations: 28 kB / 0.8279 GB, free: 12.62 MB / 0.6511 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 9.56e-05/0.725, allocations: 19.94 kB / 0.8279 GB, free: 12.6 MB / 0.6511 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.03699/0.7619, allocations: 20 MB / 0.8474 GB, free: 8.691 MB / 0.6667 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 2.163e-05/0.762, allocations: 0 / 0.8474 GB, free: 8.691 MB / 0.6667 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.001607/0.7636, allocations: 385.8 kB / 0.8478 GB, free: 8.336 MB / 0.6667 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.01444/0.778, allocations: 7.374 MB / 0.855 GB, free: 0.957 MB / 0.6667 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0008111/0.7788, allocations: 75.92 kB / 0.855 GB, free: 0.8828 MB / 0.6667 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.2822/1.061, allocations: 30.69 MB / 0.885 GB, free: 229.3 MB / 0.6667 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 3.366e-06/1.061, allocations: 1.188 kB / 0.885 GB, free: 229.3 MB / 0.6667 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.03553/1.097, allocations: 20.14 MB / 0.9047 GB, free: 222.8 MB / 0.6667 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.001765/1.098, allocations: 0.5066 MB / 0.9052 GB, free: 222.3 MB / 0.6667 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.001123/1.099, allocations: 64 kB / 0.9052 GB, free: 222.3 MB / 0.6667 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.002466/1.102, allocations: 375.8 kB / 0.9056 GB, free: 222 MB / 0.6667 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.002607/1.105, allocations: 0.8093 MB / 0.9064 GB, free: 221.6 MB / 0.6667 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.000196/1.105, allocations: 99.92 kB / 0.9065 GB, free: 221.5 MB / 0.6667 GB
Notification: Performance of sorting global known variables: time 0.002025/1.107, allocations: 2.102 MB / 0.9085 GB, free: 219.6 MB / 0.6667 GB
Notification: Performance of sort global known variables: time 2.71e-07/1.107, allocations: 0 / 0.9085 GB, free: 219.6 MB / 0.6667 GB
Notification: Performance of remove unused functions: time 0.004536/1.111, allocations: 1.802 MB / 0.9103 GB, free: 217.8 MB / 0.6667 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 2
 * Number of states: 10 (order3.delta,order3.w,order3.e1q,order3_1.delta,order3_1.w,order3_1.e1q,aVRTypeII.ExcitationSystem.x_scaled[1],aVRTypeII.derivativeBlock.x,aVRTypeII.firstOrder2.y,aVRTypeII.simpleLagLim.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 (246):
 * Single equations (assignments): 243
 * Array equations: 0
 * Algorithm blocks: 1
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 2
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 1 system
   {(100,36,5.4%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 1 system
   {(1,6)}
Notification: Performance of Backend phase and start with SimCode phase: time 0.0004707/1.112, allocations: 207 kB / 0.9105 GB, free: 217.6 MB / 0.6667 GB
Notification: Performance of simCode: created initialization part: time 0.01327/1.125, allocations: 8.92 MB / 0.9192 GB, free: 208.6 MB / 0.6667 GB
Notification: Performance of simCode: created event and clocks part: time 5.83e-06/1.125, allocations: 1.875 kB / 0.9192 GB, free: 208.6 MB / 0.6667 GB
Notification: Performance of simCode: created simulation system equations: time 0.01052/1.136, allocations: 5.89 MB / 0.925 GB, free: 202.7 MB / 0.6667 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.003729/1.139, allocations: 385.1 kB / 0.9253 GB, free: 202.3 MB / 0.6667 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.01149/1.151, allocations: 7.933 MB / 0.9331 GB, free: 194.4 MB / 0.6667 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.0009759/1.152, allocations: 1.931 MB / 0.935 GB, free: 192.4 MB / 0.6667 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001244/1.153, allocations: 272.4 kB / 0.9352 GB, free: 192.2 MB / 0.6667 GB
Notification: Performance of SimCode: time 1.823e-06/1.153, allocations: 0 / 0.9352 GB, free: 192.2 MB / 0.6667 GB
Notification: Performance of Templates: time 0.06807/1.221, allocations: 91.11 MB / 1.024 GB, free: 100.9 MB / 0.6667 GB
"
[Timeout remaining time 659]
make -j1 -f OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII.makefile [Timeout 660]
(rm -f OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII.pipe ; mkfifo OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII.pipe ; head -c 1048576 < OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII.pipe >> ../files/OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII.sim & ./OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII  -abortSlowSimulation -alarm=480 -lv LOG_STATS > OpenIPSL_dev_OpenIPSL.Examples.PSATSystems.TwoArea.ThirdOrder_AVRII.pipe 2>&1) [Timeout 480]
[Calling sys.exit(0), Time elapsed: 9.40012704115361]
Failed to read output from testmodel.py, exit status != 0:
1.229297799989581 1.2369000079999999 0.94715287
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7e3333abc680>