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.001898/0.001898, allocations: 119.1 kB / 20.45 MB, free: 1.176 MB / 14.72 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.00177/0.00177, allocations: 202.2 kB / 23.72 MB, free: 4.391 MB / 14.72 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.49/1.49, allocations: 230.5 MB / 257.4 MB, free: 7.762 MB / 206.1 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 0.001991/0.001991, allocations: 59.89 kB / 378.3 MB, free: 2.27 MB / 302.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.2529/0.2549, allocations: 53.41 MB / 431.7 MB, free: 6.52 MB / 334.1 MB
Notification: Performance of NFInst.instantiate(Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b): time 0.02883/0.2838, allocations: 17.63 MB / 449.3 MB, free: 4.812 MB / 350.1 MB
Notification: Performance of NFInst.instExpressions: time 0.01359/0.2973, allocations: 5.993 MB / 455.3 MB, free: 14.8 MB / 366.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003513/0.3009, allocations: 206.8 kB / 455.5 MB, free: 14.6 MB / 366.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.01336/0.3142, allocations: 6.164 MB / 461.7 MB, free: 8.414 MB / 366.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.009955/0.3242, allocations: 3.513 MB / 465.2 MB, free: 4.891 MB / 366.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.004026/0.3282, allocations: 1.666 MB / 466.8 MB, free: 3.223 MB / 366.1 MB
Notification: Performance of NFFlatten.flatten: time 0.01887/0.3471, allocations: 12.99 MB / 479.8 MB, free: 6.207 MB / 382.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.009855/0.3569, allocations: 6.263 MB / 486.1 MB, free: 15.86 MB / 398.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.006867/0.3638, allocations: 3.805 MB / 489.9 MB, free: 12.04 MB / 398.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.008441/0.3722, allocations: 5.051 MB / 495 MB, free: 6.973 MB / 398.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.001997/0.3742, allocations: 0.7461 MB / 495.7 MB, free: 6.227 MB / 398.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.003894/0.3781, allocations: 1.608 MB / 497.3 MB, free: 4.617 MB / 398.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.00522/0.3833, allocations: 4.488 MB / 0.49 GB, free: 120 kB / 398.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.005374/0.3887, allocations: 3.547 MB / 0.4935 GB, free: 12.55 MB / 414.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.01896/0.4077, allocations: 14.24 MB / 0.5074 GB, free: 14.25 MB / 430.1 MB
Notification: Performance of FrontEnd - DAE generated: time 1.01e-05/0.4077, allocations: 3.938 kB / 0.5074 GB, free: 14.25 MB / 430.1 MB
Notification: Performance of FrontEnd: time 2.254e-06/0.4077, allocations: 0 / 0.5074 GB, free: 14.25 MB / 430.1 MB
Notification: Performance of Transformations before backend: time 0.0006181/0.4083, allocations: 0 / 0.5074 GB, free: 14.25 MB / 430.1 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.02823/0.4365, allocations: 10.2 MB / 0.5174 GB, free: 3.965 MB / 430.1 MB
Notification: Performance of prepare preOptimizeDAE: time 5.503e-05/0.4366, allocations: 11.98 kB / 0.5174 GB, free: 3.953 MB / 430.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.04586/0.4824, allocations: 5.335 MB / 0.5226 GB, free: 14.61 MB / 446.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.02153/0.504, allocations: 8.023 MB / 0.5304 GB, free: 6.492 MB / 446.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.000519/0.5045, allocations: 448 kB / 0.5309 GB, free: 6.055 MB / 446.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.002923/0.5074, allocations: 0.6245 MB / 0.5315 GB, free: 5.43 MB / 446.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.2456/0.753, allocations: 17.42 MB / 0.5485 GB, free: 90.09 MB / 446.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0003141/0.7533, allocations: 98.3 kB / 0.5486 GB, free: 90.06 MB / 446.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0007008/0.754, allocations: 285.2 kB / 0.5488 GB, free: 89.91 MB / 446.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.003502/0.7575, allocations: 2.852 MB / 0.5516 GB, free: 89.39 MB / 446.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.02261/0.7801, allocations: 14 MB / 0.5653 GB, free: 77.35 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.07842/0.8585, allocations: 63.2 MB / 0.627 GB, free: 13.59 MB / 446.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.01888/0.8774, allocations: 7.491 MB / 0.6343 GB, free: 6.094 MB / 446.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.004971/0.8824, allocations: 4.357 MB / 0.6386 GB, free: 1.727 MB / 446.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.0244/0.9068, allocations: 11.05 MB / 0.6494 GB, free: 6.629 MB / 462.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 6.889e-05/0.9068, allocations: 64.53 kB / 0.6494 GB, free: 6.562 MB / 462.1 MB
Notification: Performance of pre-optimization done (n=293): time 6.833e-06/0.9069, allocations: 0 / 0.6494 GB, free: 6.562 MB / 462.1 MB
Notification: Performance of matching and sorting (n=359): time 0.2086/1.115, allocations: 52.79 MB / 0.701 GB, free: 1.953 MB / 0.4981 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.0002752/1.116, allocations: 410.2 kB / 0.7014 GB, free: 1.465 MB / 0.4981 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.01288/1.129, allocations: 6.94 MB / 0.7082 GB, free: 10.54 MB / 0.5137 GB
Notification: Performance of collectPreVariables (initialization): time 0.001001/1.13, allocations: 77.7 kB / 0.7082 GB, free: 10.45 MB / 0.5137 GB
Notification: Performance of collectInitialEqns (initialization): time 0.004889/1.135, allocations: 5.419 MB / 0.7135 GB, free: 4.992 MB / 0.5137 GB
Notification: Performance of collectInitialBindings (initialization): time 0.002206/1.137, allocations: 1.387 MB / 0.7149 GB, free: 3.594 MB / 0.5137 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.004853/1.142, allocations: 1.929 MB / 0.7168 GB, free: 1.652 MB / 0.5137 GB
Notification: Performance of setup shared object (initialization): time 0.0001419/1.142, allocations: 305.1 kB / 0.7171 GB, free: 1.352 MB / 0.5137 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.008413/1.15, allocations: 4.711 MB / 0.7217 GB, free: 12.63 MB / 0.5294 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.01454/1.165, allocations: 9.764 MB / 0.7312 GB, free: 484 kB / 0.5294 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.2662/1.431, allocations: 14.99 MB / 0.7458 GB, free: 180.3 MB / 0.545 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 0.0002304/1.431, allocations: 46.75 kB / 0.7459 GB, free: 180.3 MB / 0.545 GB
Notification: Performance of matching and sorting (n=1220) (initialization): time 0.0401/1.471, allocations: 20.36 MB / 0.7658 GB, free: 175.4 MB / 0.545 GB
Notification: Performance of prepare postOptimizeDAE: time 8.902e-05/1.471, allocations: 79.34 kB / 0.7658 GB, free: 175.4 MB / 0.545 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0001313/1.471, allocations: 162.4 kB / 0.766 GB, free: 175.4 MB / 0.545 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.02024/1.492, allocations: 7.331 MB / 0.7732 GB, free: 174.2 MB / 0.545 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.006413/1.498, allocations: 1.994 MB / 0.7751 GB, free: 174 MB / 0.545 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.04213/1.54, allocations: 35.82 MB / 0.8101 GB, free: 141.2 MB / 0.545 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.00851/1.549, allocations: 0.608 MB / 0.8107 GB, free: 140.6 MB / 0.545 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.001495/1.55, allocations: 0.5039 MB / 0.8112 GB, free: 140.1 MB / 0.545 GB
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.006155/1.556, allocations: 3.587 MB / 0.8147 GB, free: 136.6 MB / 0.545 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.001721/1.558, allocations: 0.6357 MB / 0.8153 GB, free: 136.3 MB / 0.545 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.0286/1.587, allocations: 13.82 MB / 0.8288 GB, free: 122.5 MB / 0.545 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 5.984e-05/1.587, allocations: 39.94 kB / 0.8288 GB, free: 122.5 MB / 0.545 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 6.388e-05/1.587, allocations: 20 kB / 0.8288 GB, free: 122.4 MB / 0.545 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 8.064e-05/1.587, allocations: 15.94 kB / 0.8289 GB, free: 122.4 MB / 0.545 GB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.04979/1.637, allocations: 25.21 MB / 0.8535 GB, free: 96.96 MB / 0.545 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 5.408e-05/1.637, allocations: 8 kB / 0.8535 GB, free: 96.95 MB / 0.545 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.002356/1.639, allocations: 467.3 kB / 0.8539 GB, free: 96.5 MB / 0.545 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.0202/1.659, allocations: 6.962 MB / 0.8607 GB, free: 89.52 MB / 0.545 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.001194/1.66, allocations: 67.94 kB / 0.8608 GB, free: 89.45 MB / 0.545 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.04298/1.703, allocations: 34.61 MB / 0.8946 GB, free: 54.77 MB / 0.545 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 9.849e-06/1.703, allocations: 11.94 kB / 0.8946 GB, free: 54.76 MB / 0.545 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.03588/1.739, allocations: 19.59 MB / 0.9137 GB, free: 35.18 MB / 0.545 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.002162/1.742, allocations: 0.5997 MB / 0.9143 GB, free: 34.59 MB / 0.545 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.002626/1.744, allocations: 64 kB / 0.9144 GB, free: 34.52 MB / 0.545 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.005154/1.749, allocations: 323.6 kB / 0.9147 GB, free: 34.21 MB / 0.545 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.001638/1.751, allocations: 270.6 kB / 0.915 GB, free: 33.94 MB / 0.545 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0007761/1.752, allocations: 92.17 kB / 0.915 GB, free: 33.85 MB / 0.545 GB
Notification: Performance of sorting global known variables: time 0.007503/1.759, allocations: 4.22 MB / 0.9192 GB, free: 29.65 MB / 0.545 GB
Notification: Performance of sort global known variables: time 1.61e-07/1.759, allocations: 288 / 0.9192 GB, free: 29.65 MB / 0.545 GB
Notification: Performance of remove unused functions: time 0.01044/1.77, allocations: 2.197 MB / 0.9213 GB, free: 27.46 MB / 0.545 GB
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.00122/1.771, allocations: 226.2 kB / 0.9215 GB, free: 27.25 MB / 0.545 GB
Notification: Performance of simCode: created initialization part: time 0.02019/1.791, allocations: 11.51 MB / 0.9328 GB, free: 15.7 MB / 0.545 GB
Notification: Performance of simCode: created event and clocks part: time 1.607e-05/1.791, allocations: 0 / 0.9328 GB, free: 15.7 MB / 0.545 GB
Notification: Performance of simCode: created simulation system equations: time 0.009717/1.801, allocations: 4.913 MB / 0.9376 GB, free: 10.74 MB / 0.545 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.008598/1.809, allocations: 0.9196 MB / 0.9385 GB, free: 9.82 MB / 0.545 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.2805/2.09, allocations: 20.71 MB / 0.9587 GB, free: 189.3 MB / 0.5606 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.007686/2.098, allocations: 5.268 MB / 0.9638 GB, free: 188.8 MB / 0.5606 GB
Notification: Performance of simCode: alias equations: time 0.005661/2.103, allocations: 2.644 MB / 0.9664 GB, free: 188.8 MB / 0.5606 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001214/2.104, allocations: 376.4 kB / 0.9668 GB, free: 188.8 MB / 0.5606 GB
Notification: Performance of SimCode: time 1.393e-06/2.104, allocations: 0 / 0.9668 GB, free: 188.8 MB / 0.5606 GB
Notification: Performance of Templates: time 0.1364/2.241, allocations: 104.3 MB / 1.069 GB, free: 97.41 MB / 0.5606 GB
"
[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=480  -emit_protected -lv LOG_STATS > Modelica_trunk_Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b.pipe 2>&1) [Timeout 480]
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.434880806133151]