Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr PowerGrids_symb_jac_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]
"Error: Unknown option --generateDynamicJacobian.
Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaServices 4.1.0+maint.om/package.mo): time 0.001364/0.001364, allocations: 116.3 kB / 17.15 MB, free: 5.91 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.001492/0.001492, allocations: 216.6 kB / 20.12 MB, free: 2.953 MB / 14.72 MB
"
[Timeout remaining time 180]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica 3.2.3+maint.om/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica 3.2.3+maint.om/package.mo): time 1.655/1.655, allocations: 207.6 MB / 230.5 MB, free: 4.016 MB / 174.1 MB
"
[Timeout remaining time 178]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/PowerGrids 1.0.3/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/PowerGrids 1.0.3/package.mo): time 0.07422/0.07422, allocations: 14.41 MB / 296.8 MB, free: 1.855 MB / 238.1 MB
"
[Timeout remaining time 180]
Using package PowerGrids with version 1.0.3 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/PowerGrids 1.0.3/package.mo)
Using package Modelica with version 3.2.3 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica 3.2.3+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_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat")
translateModel(PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat,tolerance=1e-06,outputFormat="empty",numberOfIntervals=1500,variableFilter="",fileNamePrefix="PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat") [Timeout 660]
"Notification: Modelica requested package Complex of version 3.2.3. Complex 4.1.0 is used instead which states that it is fully compatible without conversion script needed.
Notification: Modelica requested package ModelicaServices of version 3.2.3. ModelicaServices 4.1.0 is used instead which states that it is fully compatible without conversion script needed.
Notification: Performance of FrontEnd - loaded program: time 0.002203/0.002203, allocations: 75.89 kB / 418.8 MB, free: 5.5 MB / 302.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.2665/0.2687, allocations: 52.86 MB / 471.6 MB, free: 13.03 MB / 334.1 MB
Notification: Performance of NFInst.instantiate(PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat): time 0.01895/0.2876, allocations: 16.01 MB / 487.7 MB, free: 13.52 MB / 350.1 MB
Notification: Performance of NFInst.instExpressions: time 0.01415/0.3018, allocations: 6.869 MB / 494.5 MB, free: 6.637 MB / 350.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003204/0.305, allocations: 95.19 kB / 494.6 MB, free: 6.543 MB / 350.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.002805/0.3078, allocations: 0.8183 MB / 495.4 MB, free: 5.719 MB / 350.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.008001/0.3158, allocations: 2.632 MB / 498.1 MB, free: 3.094 MB / 350.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.004112/0.3199, allocations: 1.567 MB / 499.6 MB, free: 1.523 MB / 350.1 MB
[/var/lib/jenkins1/ws/OpenModelicaLibraryTestingWork/OpenModelica/OMCompiler/Compiler/NFFrontEnd/NFFunction.mo:2655:11-2655:130:writable] Error: Internal error NFFunction.Function.getBody2 got function with external section (not algorithm section)
Notification: Performance of NFFlatten.flatten: time 0.008394/0.3283, allocations: 5.087 MB / 0.4929 GB, free: 12.42 MB / 366.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.001225/0.3295, allocations: 499.1 kB / 0.4934 GB, free: 11.9 MB / 366.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.003477/0.333, allocations: 1.818 MB / 0.4951 GB, free: 10.07 MB / 366.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.003465/0.3364, allocations: 1.84 MB / 0.4969 GB, free: 8.227 MB / 366.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.0007957/0.3372, allocations: 288 kB / 0.4972 GB, free: 7.945 MB / 366.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.001973/0.3392, allocations: 0.7028 MB / 0.4979 GB, free: 7.242 MB / 366.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.0006232/0.3398, allocations: 0.6302 MB / 0.4985 GB, free: 6.609 MB / 366.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.00229/0.3421, allocations: 1.644 MB / 0.5001 GB, free: 4.957 MB / 366.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.006804/0.3489, allocations: 4.24 MB / 0.5043 GB, free: 0.7031 MB / 366.1 MB
Notification: Performance of FrontEnd - DAE generated: time 6.402e-06/0.3489, allocations: 4 kB / 0.5043 GB, free: 0.6992 MB / 366.1 MB
Notification: Performance of FrontEnd: time 2.344e-06/0.3489, allocations: 0 / 0.5043 GB, free: 0.6992 MB / 366.1 MB
Notification: Performance of Transformations before backend: time 0.0001266/0.3491, allocations: 0 / 0.5043 GB, free: 0.6992 MB / 366.1 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 507
 * Number of variables: 507
Notification: Performance of Generate backend data structure: time 0.01507/0.3641, allocations: 4.268 MB / 0.5084 GB, free: 12.36 MB / 382.1 MB
Notification: Performance of prepare preOptimizeDAE: time 5.861e-05/0.3642, allocations: 16.03 kB / 0.5085 GB, free: 12.34 MB / 382.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.001628/0.3658, allocations: 422.8 kB / 0.5089 GB, free: 11.93 MB / 382.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.004272/0.3701, allocations: 1.952 MB / 0.5108 GB, free: 9.906 MB / 382.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0001528/0.3702, allocations: 164.4 kB / 0.5109 GB, free: 9.746 MB / 382.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0003663/0.3706, allocations: 223.9 kB / 0.5111 GB, free: 9.527 MB / 382.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.004269/0.3749, allocations: 2.072 MB / 0.5132 GB, free: 7.383 MB / 382.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 4.187e-05/0.3749, allocations: 11.94 kB / 0.5132 GB, free: 7.371 MB / 382.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0001932/0.3751, allocations: 79.94 kB / 0.5132 GB, free: 7.293 MB / 382.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 5.345e-05/0.3752, allocations: 48 kB / 0.5133 GB, free: 7.246 MB / 382.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.004086/0.3793, allocations: 1.92 MB / 0.5152 GB, free: 5.324 MB / 382.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.02262/0.4019, allocations: 12.23 MB / 0.5271 GB, free: 8.055 MB / 398.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.00446/0.4063, allocations: 2.521 MB / 0.5296 GB, free: 5.367 MB / 398.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.001469/0.4078, allocations: 0.7363 MB / 0.5303 GB, free: 4.625 MB / 398.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.0001278/0.4079, allocations: 25.98 kB / 0.5303 GB, free: 4.602 MB / 398.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 4.981e-05/0.408, allocations: 60.56 kB / 0.5304 GB, free: 4.531 MB / 398.1 MB
Notification: Performance of pre-optimization done (n=194): time 3.757e-06/0.408, allocations: 0 / 0.5304 GB, free: 4.531 MB / 398.1 MB
Notification: Performance of matching and sorting (n=194): time 0.0107/0.4187, allocations: 3.407 MB / 0.5337 GB, free: 1.098 MB / 398.1 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.0001078/0.4188, allocations: 176.2 kB / 0.5339 GB, free: 0.8906 MB / 398.1 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.003132/0.4219, allocations: 1.876 MB / 0.5357 GB, free: 14.98 MB / 414.1 MB
Notification: Performance of collectPreVariables (initialization): time 0.0002364/0.4222, allocations: 69.7 kB / 0.5358 GB, free: 14.91 MB / 414.1 MB
Notification: Performance of collectInitialEqns (initialization): time 0.0009877/0.4231, allocations: 1.114 MB / 0.5368 GB, free: 13.79 MB / 414.1 MB
Notification: Performance of collectInitialBindings (initialization): time 0.0008547/0.424, allocations: 0.7242 MB / 0.5376 GB, free: 13.05 MB / 414.1 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.0007623/0.4248, allocations: 485.6 kB / 0.538 GB, free: 12.57 MB / 414.1 MB
Notification: Performance of setup shared object (initialization): time 0.0001597/0.4249, allocations: 309 kB / 0.5383 GB, free: 12.27 MB / 414.1 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.001819/0.4267, allocations: 0.8407 MB / 0.5391 GB, free: 11.42 MB / 414.1 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.002443/0.4292, allocations: 1.463 MB / 0.5406 GB, free: 9.699 MB / 414.1 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.004148/0.4333, allocations: 2.212 MB / 0.5427 GB, free: 7.238 MB / 414.1 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 1.687e-05/0.4333, allocations: 4 kB / 0.5427 GB, free: 7.234 MB / 414.1 MB
Notification: Performance of matching and sorting (n=343) (initialization): time 0.01053/0.4439, allocations: 3.772 MB / 0.5464 GB, free: 3.379 MB / 414.1 MB
Notification: Performance of prepare postOptimizeDAE: time 3.555e-05/0.4439, allocations: 12 kB / 0.5464 GB, free: 3.367 MB / 414.1 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 3.713e-05/0.444, allocations: 16 kB / 0.5464 GB, free: 3.352 MB / 414.1 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.009731/0.4537, allocations: 1.816 MB / 0.5482 GB, free: 1.5 MB / 414.1 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.002644/0.4563, allocations: 0.5305 MB / 0.5487 GB, free: 0.9688 MB / 414.1 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.03234/0.4887, allocations: 21.41 MB / 0.5696 GB, free: 10.01 MB / 446.1 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.002911/0.4916, allocations: 278.2 kB / 0.5699 GB, free: 9.738 MB / 446.1 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0002488/0.4918, allocations: 104 kB / 0.57 GB, free: 9.637 MB / 446.1 MB
Notification: Performance of preBalanceInitialSystem (initialization_lambda0): time 0.002244/0.4941, allocations: 1.079 MB / 0.5711 GB, free: 8.551 MB / 446.1 MB
Notification: Performance of partitionIndependentBlocks (initialization_lambda0): time 0.001989/0.4961, allocations: 1.354 MB / 0.5724 GB, free: 6.934 MB / 446.1 MB
Notification: Performance of analyzeInitialSystem (initialization_lambda0): time 0.003366/0.4994, allocations: 2.056 MB / 0.5744 GB, free: 4.629 MB / 446.1 MB
Notification: Performance of solveInitialSystemEqSystem (initialization_lambda0): time 1.019e-05/0.4994, allocations: 4 kB / 0.5744 GB, free: 4.625 MB / 446.1 MB
Notification: Performance of matching and sorting (n=343) (initialization_lambda0): time 0.007044/0.5065, allocations: 2.96 MB / 0.5773 GB, free: 1.586 MB / 446.1 MB
Notification: Performance of prepare postOptimizeDAE: time 3.222e-05/0.5065, allocations: 8 kB / 0.5773 GB, free: 1.578 MB / 446.1 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 2.493e-05/0.5065, allocations: 16 kB / 0.5773 GB, free: 1.562 MB / 446.1 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.007354/0.5139, allocations: 1.312 MB / 0.5786 GB, free: 224 kB / 446.1 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.002707/0.5166, allocations: 0.6046 MB / 0.5792 GB, free: 15.61 MB / 462.1 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.01796/0.5346, allocations: 16.56 MB / 0.5953 GB, free: 13.64 MB / 478.1 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.002761/0.5373, allocations: 194.9 kB / 0.5955 GB, free: 13.45 MB / 478.1 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0002952/0.5376, allocations: 99.98 kB / 0.5956 GB, free: 13.35 MB / 478.1 MB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 71
 * Number of states: 0 ()
 * Number of discrete variables: 5 (PSS.firstWashoutVsi2.integrator.local_reset,PSS.secondWashoutVsi1.integrator.local_reset,PSS.firstWashoutVsi1.integrator.local_reset,AVR.firstOrderLim.I.local_reset,TGOV.firstOrderLim.I.local_reset)
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (286):
 * Single equations (assignments): 275
 * Array equations: 0
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 11
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 5 systems
   {(2,0,100.0%), (2,0,100.0%), (2,0,100.0%), (3,0,66.7%), (3,0,66.7%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 6 systems
   {(38,0), (2,0), (2,0), (2,0), (2,0), (10,0)}
Notification: Performance of prepare postOptimizeDAE: time 0.0006135/0.5382, allocations: 339.5 kB / 0.5959 GB, free: 13.01 MB / 478.1 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0006368/0.5389, allocations: 258.4 kB / 0.5962 GB, free: 12.76 MB / 478.1 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.004597/0.5435, allocations: 2.097 MB / 0.5982 GB, free: 10.64 MB / 478.1 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 2.09e-05/0.5435, allocations: 15.94 kB / 0.5983 GB, free: 10.63 MB / 478.1 MB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 4.739e-06/0.5435, allocations: 3.938 kB / 0.5983 GB, free: 10.62 MB / 478.1 MB
Notification: Performance of postOpt removeConstants (simulation): time 0.001103/0.5446, allocations: 0.5068 MB / 0.5988 GB, free: 10.1 MB / 478.1 MB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.0002858/0.5449, allocations: 36 kB / 0.5988 GB, free: 10.06 MB / 478.1 MB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.001352/0.5462, allocations: 79.89 kB / 0.5989 GB, free: 9.984 MB / 478.1 MB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.000294/0.5465, allocations: 149.8 kB / 0.599 GB, free: 9.836 MB / 478.1 MB
Notification: Performance of postOpt createDAEmodeBDAE (simulation): time 0.005742/0.5523, allocations: 2.092 MB / 0.6011 GB, free: 7.734 MB / 478.1 MB
Notification: Performance of postOpt symbolicJacobianDAE (simulation): time 0.00522/0.5575, allocations: 2.662 MB / 0.6037 GB, free: 5.051 MB / 478.1 MB
Notification: Performance of postOpt setEvaluationStage (simulation): time 0.001299/0.5588, allocations: 0.6559 MB / 0.6043 GB, free: 4.398 MB / 478.1 MB
Notification: Performance of sorting global known variables: time 0.002342/0.5611, allocations: 1.214 MB / 0.6055 GB, free: 3.168 MB / 478.1 MB
Notification: Performance of Backend: time 7.31e-07/0.5611, allocations: 0 / 0.6055 GB, free: 3.168 MB / 478.1 MB
Notification: Performance of simCode: created initialization part: time 0.2322/0.7933, allocations: 6.769 MB / 0.6121 GB, free: 131 MB / 478.1 MB
Notification: Performance of SimCode: time 0.01265/0.806, allocations: 5.382 MB / 0.6173 GB, free: 128.6 MB / 478.1 MB
Notification: Performance of Templates: time 0.1338/0.9398, allocations: 50.74 MB / 0.6669 GB, free: 86.45 MB / 478.1 MB
"
[Timeout remaining time 659]
make -j1 -f PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.makefile [Timeout 660]
(rm -f PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe ; mkfifo PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe ; head -c 1048576 < PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe >> ../files/PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.sim & ./PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat  -nls=kinsol -lv=LOG_INIT_HOMOTOPY -abortSlowSimulation -alarm=50 -lv LOG_STATS > PowerGrids_symb_jac_PowerGrids.Examples.Tutorial.GridOperation.Controlled.ControlledGridWithReferenceCalculationSat.pipe 2>&1) [Timeout 50]
[Calling os._exit(0), Time elapsed: 7.44202571499045]
Failed to read output from testmodel.py, exit status != 0:
0.9495707380119711 0.964353428 0.6122071210000001
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7f9535cbf340>