Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.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.001687/0.001687, allocations: 104.3 kB / 19.77 MB, free: 2.051 MB / 14.72 MB
"
[Timeout remaining time 180]
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.001588/0.001588, allocations: 214.9 kB / 23.07 MB, free: 4.844 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.471/1.471, allocations: 230.7 MB / 256.9 MB, free: 7.977 MB / 206.1 MB
"
[Timeout remaining time 178]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/PowerGrids 2.0.0-develop/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/PowerGrids 2.0.0-develop/package.mo): time 0.08216/0.08216, allocations: 16.93 MB / 330.2 MB, free: 2.367 MB / 254.1 MB
"
[Timeout remaining time 180]
Using package PowerGrids with version 2.0.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/PowerGrids 2.0.0-develop/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 Complex with version 4.1.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/Complex 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(PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat,tolerance=1e-06,outputFormat="empty",numberOfIntervals=1500,variableFilter="",fileNamePrefix="PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat")
translateModel(PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat,tolerance=1e-06,outputFormat="empty",numberOfIntervals=1500,variableFilter="",fileNamePrefix="PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat") [Timeout 660]
"Notification: Performance of FrontEnd - Absyn->SCode: time 1.676e-05/1.676e-05, allocations: 2.281 kB / 461.3 MB, free: 1.777 MB / 318.1 MB
Notification: Performance of NFInst.instantiate(PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat): time 0.0378/0.03782, allocations: 35.15 MB / 496.4 MB, free: 14.47 MB / 366.1 MB
Notification: Performance of NFInst.instExpressions: time 0.01957/0.05739, allocations: 9.946 MB / 0.4945 GB, free: 4.5 MB / 366.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.005507/0.06289, allocations: 146.8 kB / 0.4946 GB, free: 4.355 MB / 366.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.004904/0.0678, allocations: 1.342 MB / 0.4959 GB, free: 3.004 MB / 366.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.01286/0.08065, allocations: 4.088 MB / 0.4999 GB, free: 14.93 MB / 382.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.006859/0.08751, allocations: 2.611 MB / 0.5025 GB, free: 12.36 MB / 382.1 MB
Notification: Performance of NFFlatten.flatten: time 0.01533/0.1028, allocations: 10.6 MB / 0.5128 GB, free: 1.738 MB / 382.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.2541/0.357, allocations: 2.215 MB / 0.515 GB, free: 19.61 MB / 382.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.008542/0.3655, allocations: 3.437 MB / 0.5183 GB, free: 19.5 MB / 382.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.007735/0.3733, allocations: 3.183 MB / 0.5215 GB, free: 18.87 MB / 382.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.001899/0.3752, allocations: 410.1 kB / 0.5218 GB, free: 18.87 MB / 382.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.005263/0.3804, allocations: 1.049 MB / 0.5229 GB, free: 18.87 MB / 382.1 MB
Notification: Performance of combineBinaries: time 0.01739/0.3978, allocations: 13.06 MB / 0.5356 GB, free: 13.66 MB / 382.1 MB
Notification: Performance of replaceArrayConstructors: time 0.008912/0.4067, allocations: 7.528 MB / 0.543 GB, free: 9.398 MB / 382.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.003883/0.4106, allocations: 426.4 kB / 0.5434 GB, free: 9.398 MB / 382.1 MB
Notification: Performance of FrontEnd: time 0.001813/0.4124, allocations: 200.1 kB / 0.5436 GB, free: 9.363 MB / 382.1 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 862 (708)
 * Number of variables: 862 (862)
Notification: Performance of [SIM] Bindings: time 0.03718/0.4496, allocations: 30.31 MB / 0.5732 GB, free: 10.32 MB / 398.1 MB
Notification: Performance of [SIM] FunctionAlias: time 0.0056/0.4552, allocations: 2.992 MB / 0.5761 GB, free: 8.719 MB / 398.1 MB
Notification: Performance of [SIM] Early Inline: time 0.02562/0.4808, allocations: 16.97 MB / 0.5927 GB, free: 10.11 MB / 414.1 MB
Notification: Performance of [SIM] Simplify 1: time 0.006477/0.4873, allocations: 1.865 MB / 0.5945 GB, free: 8.164 MB / 414.1 MB
Warning: NBAlias.setStartFixed: Alias set with conflicting unfixed start values detected. Use -d=dumprepl for more information.
Notification: Performance of [SIM] Alias: time 0.03026/0.5176, allocations: 16.52 MB / 0.6106 GB, free: 6.352 MB / 430.1 MB
Notification: Performance of [SIM] Simplify 2: time 0.004162/0.5217, allocations: 1.554 MB / 0.6121 GB, free: 4.695 MB / 430.1 MB
Notification: Performance of [SIM] Remove Stream: time 0.001755/0.5235, allocations: 1.067 MB / 0.6132 GB, free: 3.586 MB / 430.1 MB
Notification: Performance of [SIM] Detect States: time 0.003193/0.5267, allocations: 2.631 MB / 0.6157 GB, free: 0.8906 MB / 430.1 MB
Notification: Performance of [SIM] Events: time 0.001871/0.5285, allocations: 0.8365 MB / 0.6166 GB, free: 60 kB / 430.1 MB
Notification: Performance of [SIM] Partitioning: time 0.006503/0.535, allocations: 4.452 MB / 0.6209 GB, free: 11.2 MB / 446.1 MB
Notification: Performance of [SIM] Causalize: time 0.01877/0.5538, allocations: 10.45 MB / 0.6311 GB, free: 352 kB / 446.1 MB
Notification: Performance of [SIM] After Index Reduction Inline: time 0.01217/0.566, allocations: 8.501 MB / 0.6394 GB, free: 7.91 MB / 462.1 MB
Notification: Performance of [INI] Simplify: time 0.01741/0.5834, allocations: 7.364 MB / 0.6466 GB, free: 460 kB / 462.1 MB
Notification: Performance of [INI] Inline: time 0.02888/0.6123, allocations: 19.26 MB / 0.6654 GB, free: 13.41 MB / 494.1 MB
Notification: Performance of [INI] Partitioning: time 0.001874/0.6142, allocations: 361.5 kB / 0.6658 GB, free: 12.98 MB / 494.1 MB
Notification: Performance of [INI] Cleanup: time 0.008287/0.6224, allocations: 3.72 MB / 0.6694 GB, free: 9.297 MB / 494.1 MB
Notification: Performance of [INI] Causalize: time 0.08671/0.7091, allocations: 39.77 MB / 0.7082 GB, free: 1.266 MB / 0.5138 GB
Notification: Performance of [INI] Tearing: time 0.3301/1.039, allocations: 5.53 MB / 0.7136 GB, free: 128.3 MB / 0.5138 GB
Notification: Performance of [SIM] Initialization: time 3.366e-06/1.039, allocations: 0 / 0.7136 GB, free: 128.3 MB / 0.5138 GB
Notification: Performance of [SIM] DAE-Mode: time 0.006312/1.046, allocations: 3.76 MB / 0.7173 GB, free: 127 MB / 0.5138 GB
Notification: Performance of [SIM] Remove Dummies: time 7.096e-05/1.046, allocations: 18.12 kB / 0.7173 GB, free: 127 MB / 0.5138 GB
Notification: Performance of [SIM] Tearing: time 0.00202/1.048, allocations: 1.377 MB / 0.7187 GB, free: 126.7 MB / 0.5138 GB
Notification: Performance of [SIM] Categorize: time 0.0001826/1.048, allocations: 32.23 kB / 0.7187 GB, free: 126.7 MB / 0.5138 GB
Notification: Performance of [SIM] Solve: time 0.02805/1.076, allocations: 18.27 MB / 0.7366 GB, free: 124.6 MB / 0.5138 GB
Notification: Performance of [SIM] Jacobian: time 0.02135/1.097, allocations: 26.63 MB / 0.7626 GB, free: 108.5 MB / 0.5138 GB
Notification: Partition statistics after passing the back-end:
 * Number of ODE partitions: ..................... 0
 * Number of algebraic partitions: ............... 44
 * Number of ODE event partitions: ............... 1
 * Number of algebraic event partitions: ......... 8
 * Number of clocked partitions: ................. 0
 * Number of initial partitions: ................. 1
 * Number of initial(lambda=0) partitions: ....... 1
Notification: Variable statistics after passing the back-end:
 * Number of states: ............................. 16 (16) {GEN.theta, TGOV.omegaPu, GEN.lambdafPu, GEN.lambdaDPu, GEN.lambdaQ1Pu, GEN.lambdaQ2Pu, TGOV.firstOrderLim.lim.simplifiedExpr, TGOV.leadLag.firstOrder.y, AVR.leadLag.firstOrder.y, AVR.firstOrderLim.lim.simplifiedExpr, PSS.firstWashoutVsi1.integrator.y, PSS.secondWashoutVsi1.integrator.y, PSS.firstWashoutVsi2.integrator.y, PSS.leadLag1.firstOrder.y, PSS.leadLag2.firstOrder.y, PSS.add2.u2}
 * Number of discrete states: .................... 0 (0) {}
 * Number of clocked states: ..................... 0 (0) {}
 * Number of discrete variables: ................. 44 (44) {$SEV_42, $SEV_41, $SEV_40, $SEV_39, $SEV_38, $SEV_37, $SEV_36, $SEV_35, $SEV_34, $SEV_33, $SEV_32, $SEV_31, $SEV_30, $SEV_29, $SEV_28, $SEV_27, $SEV_26, $SEV_25, $SEV_24, $SEV_23, $SEV_22, $SEV_21, $SEV_20, $SEV_19, $SEV_18, $SEV_17, $SEV_16, $SEV_15, $SEV_14, $SEV_13, $SEV_12, $SEV_11, $SEV_10, $SEV_9, $SEV_8, $SEV_7, $SEV_6, $SEV_5, $SEV_4, $SEV_3, $SEV_2, $SEV_1, $SEV_0, $TEV_0}
 * Number of clocks: ............................. 0 (0) {}
 * Number of top-level inputs: ................... 0 (0) {}
Notification: [Simulation] Strong Component statistics after passing the back-end:
 * Number of single strong components: ........... 425 (scalar:425, array:0, record:0)
 * Number of multi strong components: ............ 0 (algorithm:0, when:0, if:0, tuple:18)
 * Number of for-loop strong components: ......... 0 (resizable: 0, generic: 0, entwined:0)
 * Number of algebraic-loop strong components: ... 3 (linear: 3, nonlinear:0)
Notification: [Initialization] Strong Component statistics after passing the back-end:
 * Number of single strong components: ........... 874 (scalar:874, array:0, record:0)
 * Number of multi strong components: ............ 0 (algorithm:0, when:0, if:0, tuple:30)
 * Number of for-loop strong components: ......... 0 (resizable: 0, generic: 0, entwined:0)
 * Number of algebraic-loop strong components: ... 13 (linear: 13, nonlinear:0)
Notification: [Initialization (lambda=0)] Strong Component statistics after passing the back-end:
 * Number of single strong components: ........... 908 (scalar:908, array:0, record:0)
 * Number of multi strong components: ............ 0 (algorithm:0, when:0, if:0, tuple:30)
 * Number of for-loop strong components: ......... 0 (resizable: 0, generic: 0, entwined:0)
 * Number of algebraic-loop strong components: ... 12 (linear: 12, nonlinear:0)
Notification: Performance of backend: time 0.0005938/1.098, allocations: 341.4 kB / 0.7629 GB, free: 108.2 MB / 0.5138 GB
Notification: Performance of SimCode: time 0.0274/1.125, allocations: 24.89 MB / 0.7872 GB, free: 92.59 MB / 0.5138 GB
Notification: Performance of Templates: time 0.09883/1.224, allocations: 71.16 MB / 0.8567 GB, free: 22.67 MB / 0.5138 GB
"
[Timeout remaining time 659]
make -j1 -f PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.makefile [Timeout 660]
(rm -f PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe ; mkfifo PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe ; head -c 1048576 < PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe >> ../files/PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.sim & ./PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat  -abortSlowSimulation -alarm=480 -lv LOG_STATS > PowerGrids_dev_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe 2>&1) [Timeout 480]
[Calling os._exit(0), Time elapsed: 8.865558649005834]
Failed to read output from testmodel.py, exit status != 0:
1.2328788039740175 1.242938988 0.827910289
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7f4183f56dd0>