Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.conf.json
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaServices trunk/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaServices trunk/package.mo): time 0.002594/0.002594, allocations: 103.5 kB / 20.97 MB, free: 3.453 MB / 18.57 MB
"
[Timeout remaining time 180]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/Complex trunk/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/Complex trunk/package.mo): time 0.002465/0.002465, allocations: 160.8 kB / 24.27 MB, free: 156 kB / 18.57 MB
"
[Timeout remaining time 180]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica trunk/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica trunk/package.mo): time 1.652/1.652, allocations: 177 MB / 204.4 MB, free: 5.613 MB / 186.7 MB
"
[Timeout remaining time 178]
Using package Modelica with version trunk (/home/hudson/saved_omc/libraries/.openmodelica/libraries/Modelica trunk/package.mo)
Using package Complex with version trunk (/home/hudson/saved_omc/libraries/.openmodelica/libraries/Complex trunk/package.mo)
Using package ModelicaServices with version trunk (/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaServices trunk/package.mo)
Running command: translateModel(Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b,tolerance=1e-06,outputFormat="mat",numberOfIntervals=5028,variableFilter="time|inertia.phi|inertia.w",fileNamePrefix="Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b")
translateModel(Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b,tolerance=1e-06,outputFormat="mat",numberOfIntervals=5028,variableFilter="time|inertia.phi|inertia.w",fileNamePrefix="Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 1.443e-06/1.443e-06, allocations: 0 / 272.2 MB, free: 1.766 MB / 250.7 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 2.701e-05/2.845e-05, allocations: 2.312 kB / 272.2 MB, free: 1.762 MB / 250.7 MB
Notification: Performance of NFInst.instantiate(Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b): time 0.1403/0.1403, allocations: 19.84 MB / 292.1 MB, free: 14.01 MB / 266.7 MB
Notification: Performance of NFInst.instExpressions: time 0.01164/0.152, allocations: 6.098 MB / 298.2 MB, free: 13.28 MB / 266.7 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003677/0.1556, allocations: 204.1 kB / 298.4 MB, free: 13.21 MB / 266.7 MB
Notification: Performance of NFTyping.typeComponents: time 0.01223/0.1679, allocations: 6.832 MB / 305.2 MB, free: 11.06 MB / 266.7 MB
Notification: Performance of NFTyping.typeBindings: time 0.008623/0.1765, allocations: 3.615 MB / 308.8 MB, free: 8.777 MB / 266.7 MB
Notification: Performance of NFTyping.typeClassSections: time 0.003631/0.1801, allocations: 1.927 MB / 310.7 MB, free: 7.57 MB / 266.7 MB
Notification: Performance of NFFlatten.flatten: time 0.01632/0.1964, allocations: 15.1 MB / 325.8 MB, free: 12.12 MB / 282.7 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.01286/0.2093, allocations: 8.082 MB / 333.9 MB, free: 3.957 MB / 282.7 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.01333/0.2226, allocations: 5.805 MB / 339.7 MB, free: 14.14 MB / 298.7 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.01122/0.2339, allocations: 5.963 MB / 345.7 MB, free: 8.164 MB / 298.7 MB
Notification: Performance of NFPackage.collectConstants: time 0.002642/0.2365, allocations: 0.7773 MB / 346.5 MB, free: 7.387 MB / 298.7 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.005153/0.2417, allocations: 1.69 MB / 348.2 MB, free: 5.695 MB / 298.7 MB
Notification: Performance of NFScalarize.scalarize: time 0.007369/0.249, allocations: 4.789 MB / 352.9 MB, free: 0.8906 MB / 298.7 MB
Notification: Performance of NFVerifyModel.verify: time 0.007222/0.2562, allocations: 2.918 MB / 355.9 MB, free: 13.96 MB / 314.7 MB
Notification: Performance of NFConvertDAE.convert: time 0.02254/0.2788, allocations: 14.57 MB / 370.4 MB, free: 15.35 MB / 330.7 MB
Notification: Performance of FrontEnd - DAE generated: time 6.562e-06/0.2788, allocations: 0 / 370.4 MB, free: 15.35 MB / 330.7 MB
Notification: Performance of FrontEnd: time 2.024e-06/0.2788, allocations: 0 / 370.4 MB, free: 15.35 MB / 330.7 MB
Notification: Performance of Transformations before backend: time 0.0005884/0.2794, allocations: 0 / 370.4 MB, free: 15.35 MB / 330.7 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 2488
 * Number of variables: 2488
Notification: Performance of Generate backend data structure: time 0.03146/0.3108, allocations: 11.85 MB / 382.3 MB, free: 3.414 MB / 330.7 MB
Notification: Performance of prepare preOptimizeDAE: time 4.17e-05/0.3109, allocations: 11.98 kB / 382.3 MB, free: 3.402 MB / 330.7 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.05147/0.3624, allocations: 6.258 MB / 388.6 MB, free: 13.13 MB / 346.7 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.02246/0.3848, allocations: 7.346 MB / 395.9 MB, free: 5.699 MB / 346.7 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0004851/0.3853, allocations: 448 kB / 396.3 MB, free: 5.262 MB / 346.7 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.002056/0.3874, allocations: 0.6055 MB / 396.9 MB, free: 4.656 MB / 346.7 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.03106/0.4184, allocations: 11.39 MB / 408.3 MB, free: 7.758 MB / 362.7 MB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0003908/0.4188, allocations: 91.31 kB / 408.4 MB, free: 7.668 MB / 362.7 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.001278/0.4201, allocations: 279.8 kB / 408.7 MB, free: 7.395 MB / 362.7 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.005613/0.4257, allocations: 2.858 MB / 411.6 MB, free: 4.535 MB / 362.7 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.02362/0.4493, allocations: 5.927 MB / 417.5 MB, free: 14.59 MB / 378.7 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.3248/0.7741, allocations: 78.78 MB / 496.3 MB, free: 52.15 MB / 378.8 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.0175/0.7916, allocations: 4.852 MB / 0.4894 GB, free: 51.35 MB / 378.8 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.003214/0.7948, allocations: 1.495 MB / 0.4908 GB, free: 50.9 MB / 378.8 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.01927/0.8141, allocations: 7.754 MB / 0.4984 GB, free: 45.66 MB / 378.8 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 4.997e-05/0.8141, allocations: 78.8 kB / 0.4985 GB, free: 45.58 MB / 378.8 MB
Notification: Performance of pre-optimization done (n=293): time 5.991e-06/0.8141, allocations: 0 / 0.4985 GB, free: 45.58 MB / 378.8 MB
Notification: Performance of matching and sorting (n=359): time 0.1676/0.9818, allocations: 41.23 MB / 0.5387 GB, free: 5.023 MB / 378.8 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.0001137/0.9819, allocations: 406.2 kB / 0.5391 GB, free: 4.539 MB / 378.8 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.01273/0.9946, allocations: 7.776 MB / 0.5467 GB, free: 12.97 MB / 394.8 MB
Notification: Performance of collectPreVariables (initialization): time 0.0009187/0.9955, allocations: 81.7 kB / 0.5468 GB, free: 12.89 MB / 394.8 MB
Notification: Performance of collectInitialEqns (initialization): time 0.006335/1.002, allocations: 6.025 MB / 0.5527 GB, free: 7.23 MB / 394.8 MB
Notification: Performance of collectInitialBindings (initialization): time 0.003004/1.005, allocations: 1.511 MB / 0.5542 GB, free: 5.738 MB / 394.8 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.00433/1.009, allocations: 2.39 MB / 0.5565 GB, free: 3.332 MB / 394.8 MB
Notification: Performance of setup shared object (initialization): time 0.0002538/1.009, allocations: 476.8 kB / 0.5569 GB, free: 2.863 MB / 394.8 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.004673/1.014, allocations: 1.685 MB / 0.5586 GB, free: 1.172 MB / 394.8 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.01296/1.027, allocations: 9.309 MB / 0.5677 GB, free: 4.598 MB / 410.8 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.1472/1.174, allocations: 12.73 MB / 0.5801 GB, free: 109 MB / 410.8 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 0.000226/1.175, allocations: 46.44 kB / 0.5802 GB, free: 109 MB / 410.8 MB
Notification: Performance of matching and sorting (n=1220) (initialization): time 0.03713/1.212, allocations: 12.98 MB / 0.5928 GB, free: 107.6 MB / 410.8 MB
Notification: Performance of prepare postOptimizeDAE: time 9.658e-05/1.212, allocations: 76.56 kB / 0.5929 GB, free: 107.6 MB / 410.8 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0001355/1.212, allocations: 163.8 kB / 0.5931 GB, free: 107.6 MB / 410.8 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.02274/1.235, allocations: 5.466 MB / 0.5984 GB, free: 107.4 MB / 410.8 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.006021/1.241, allocations: 2 MB / 0.6004 GB, free: 107.3 MB / 410.8 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.02903/1.27, allocations: 15.45 MB / 0.6154 GB, free: 99.23 MB / 410.8 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.00849/1.278, allocations: 0.7175 MB / 0.6161 GB, free: 98.68 MB / 410.8 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.001497/1.28, allocations: 0.4972 MB / 0.6166 GB, free: 98.26 MB / 410.8 MB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 749
 * Number of states: 0 ()
 * Number of discrete variables: 72 (rod3.color[3],rod3.color[2],rod3.color[1],rod1.color[3],rod1.color[2],rod1.color[1],cylinder.boxColor[3],cylinder.boxColor[2],cylinder.boxColor[1],b2.cylinderColor[3],b2.cylinderColor[2],b2.cylinderColor[1],b1.cylinderColor[3],b1.cylinderColor[2],b1.cylinderColor[1],cylPosition.color[3],cylPosition.color[2],cylPosition.color[1],mid.color[3],mid.color[2],mid.color[1],crank4.color[3],crank4.color[2],crank4.color[1],crank4.body.sphereColor[3],crank4.body.sphereColor[2],crank4.body.sphereColor[1],crank3.color[3],crank3.color[2],crank3.color[1],crank3.body.sphereColor[3],crank3.body.sphereColor[2],crank3.body.sphereColor[1],crank2.color[3],crank2.color[2],crank2.color[1],crank2.body.sphereColor[3],crank2.body.sphereColor[2],crank2.body.sphereColor[1],crank1.color[3],crank1.color[2],crank1.color[1],crank1.body.sphereColor[3],crank1.body.sphereColor[2],crank1.body.sphereColor[1],bearing.cylinderColor[3],bearing.cylinderColor[2],bearing.cylinderColor[1],connectingRod.color[3],connectingRod.color[2],connectingRod.color[1],connectingRod.body.sphereColor[3],connectingRod.body.sphereColor[2],connectingRod.body.sphereColor[1],piston.color[3],piston.color[2],piston.color[1],piston.body.sphereColor[3],piston.body.sphereColor[2],piston.body.sphereColor[1],world.gravityArrowColor[3],world.gravityArrowColor[2],world.gravityArrowColor[1],world.axisColor_x[3],world.axisColor_x[2],world.axisColor_x[1],world.groundColor[3],world.groundColor[2],world.groundColor[1],world.gravitySphereColor[3],world.gravitySphereColor[2],world.gravitySphereColor[1])
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (1081):
 * Single equations (assignments): 1075
 * Array equations: 3
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 3
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 2 systems
   {(8,96,51.6%), (3,5,88.9%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 1 system
   {(2,4)}
Notification: Performance of prepare postOptimizeDAE: time 0.003636/1.283, allocations: 1.011 MB / 0.6176 GB, free: 97.65 MB / 410.8 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.001765/1.285, allocations: 0.7439 MB / 0.6183 GB, free: 97.3 MB / 410.8 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.02341/1.308, allocations: 7.814 MB / 0.626 GB, free: 90.06 MB / 410.8 MB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 5.874e-05/1.309, allocations: 36 kB / 0.626 GB, free: 90.03 MB / 410.8 MB
Notification: Performance of postOpt constantLinearSystem (simulation): time 3.174e-05/1.309, allocations: 23.94 kB / 0.626 GB, free: 90 MB / 410.8 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 6.308e-05/1.309, allocations: 15.94 kB / 0.626 GB, free: 89.99 MB / 410.8 MB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.04633/1.355, allocations: 19.63 MB / 0.6452 GB, free: 70.11 MB / 410.8 MB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 3.839e-05/1.355, allocations: 4 kB / 0.6452 GB, free: 70.1 MB / 410.8 MB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.002227/1.357, allocations: 467.3 kB / 0.6457 GB, free: 69.64 MB / 410.8 MB
Notification: Performance of postOpt tearingSystem (simulation): time 0.0222/1.379, allocations: 5.118 MB / 0.6507 GB, free: 64.51 MB / 410.8 MB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0008897/1.38, allocations: 64 kB / 0.6507 GB, free: 64.45 MB / 410.8 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.02837/1.409, allocations: 14.64 MB / 0.665 GB, free: 49.54 MB / 410.8 MB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 5.63e-06/1.409, allocations: 11.94 kB / 0.665 GB, free: 49.53 MB / 410.8 MB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.02664/1.435, allocations: 9.77 MB / 0.6746 GB, free: 39.55 MB / 410.8 MB
Notification: Performance of postOpt removeConstants (simulation): time 0.00237/1.438, allocations: 0.6961 MB / 0.6752 GB, free: 38.86 MB / 410.8 MB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.002098/1.44, allocations: 62.95 kB / 0.6753 GB, free: 38.8 MB / 410.8 MB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.005365/1.445, allocations: 415.3 kB / 0.6757 GB, free: 38.4 MB / 410.8 MB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.001311/1.446, allocations: 266.6 kB / 0.676 GB, free: 38.14 MB / 410.8 MB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0003286/1.447, allocations: 99.98 kB / 0.676 GB, free: 38.04 MB / 410.8 MB
Notification: Performance of sorting global known variables: time 0.005604/1.452, allocations: 3.455 MB / 0.6794 GB, free: 34.6 MB / 410.8 MB
Notification: Performance of sort global known variables: time 1.91e-07/1.452, allocations: 4.031 kB / 0.6794 GB, free: 34.6 MB / 410.8 MB
Notification: Performance of remove unused functions: time 0.01027/1.463, allocations: 2.495 MB / 0.6819 GB, free: 32.11 MB / 410.8 MB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 26
 * Number of states: 2 (inertia.phi,inertia.w)
 * 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 (231):
 * Single equations (assignments): 225
 * Array equations: 3
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 3
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 2 systems
   {(7,90,55.1%), (2,4,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 1 system
   {(2,6)}
Notification: Performance of Backend phase and start with SimCode phase: time 0.0008118/1.463, allocations: 226.8 kB / 0.6821 GB, free: 31.89 MB / 410.8 MB
Notification: Performance of simCode: created initialization part: time 0.01397/1.477, allocations: 7.428 MB / 0.6893 GB, free: 24.4 MB / 410.8 MB
Notification: Performance of simCode: created event and clocks part: time 1.832e-05/1.477, allocations: 9.203 kB / 0.6893 GB, free: 24.39 MB / 410.8 MB
Notification: Performance of simCode: created simulation system equations: time 0.006526/1.484, allocations: 3.248 MB / 0.6925 GB, free: 21.08 MB / 410.8 MB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.005654/1.49, allocations: 0.9803 MB / 0.6935 GB, free: 20.14 MB / 410.8 MB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.02953/1.519, allocations: 16.39 MB / 0.7095 GB, free: 3.543 MB / 410.8 MB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.007293/1.526, allocations: 4.819 MB / 0.7142 GB, free: 14.69 MB / 426.8 MB
Notification: Performance of simCode: alias equations: time 0.007429/1.534, allocations: 2.228 MB / 0.7164 GB, free: 12.45 MB / 426.8 MB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001792/1.536, allocations: 400.4 kB / 0.7167 GB, free: 12.06 MB / 426.8 MB
Notification: Performance of SimCode: time 1.754e-06/1.536, allocations: 0 / 0.7167 GB, free: 12.06 MB / 426.8 MB
Notification: Performance of Templates: time 0.2934/1.829, allocations: 99.94 MB / 0.8143 GB, free: 57.16 MB / 426.8 MB
"
[Timeout remaining time 658]
make -j1 -f Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.makefile [Timeout 660]
(rm -f Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.pipe ; mkfifo Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.pipe ; head -c 1048576 < Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.pipe >> ../files/Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.sim & ./Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b -abortSlowSimulation -alarm=240  -emit_protected -lv LOG_STATS > Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.pipe 2>&1) [Timeout 240]
diffSimulationResults("Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b_res.mat","/var/lib/jenkins/ws/OpenModelicaLibraryTestingWork/Reference-modelica.org/ReferenceResults/MAP-LIB_ReferenceResults/v4.1.0/Modelica/Mechanics/MultiBody/Examples/Loops/Engine1b/Engine1b.csv","/var/lib/jenkins/ws/OpenModelicaLibraryTestingWork/OpenModelicaLibraryTesting/files/Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.diff",relTol=0.003,relTolDiffMinMax=0.003,rangeDelta=0.001) [Timeout 660]
""
[Timeout remaining time 660]
Reference file matches
[Calling sys.exit(0), Time elapsed: 9.21405885904096]