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.001811/0.001811, allocations: 107 kB / 19.8 MB, free: 2.5 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.001907/0.001907, allocations: 215.2 kB / 23 MB, free: 5.574 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.422/1.422, allocations: 230.2 MB / 256.2 MB, free: 8.523 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.001825/0.001825, allocations: 63.89 kB / 376.5 MB, free: 3.551 MB / 302.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.2577/0.2595, allocations: 53.33 MB / 429.8 MB, free: 7.691 MB / 334.1 MB
Notification: Performance of NFInst.instantiate(Modelica.Mechanics.MultiBody.Examples.Loops.Engine1b): time 0.02324/0.2827, allocations: 20.54 MB / 450.4 MB, free: 3.062 MB / 350.1 MB
Notification: Performance of NFInst.instExpressions: time 0.01496/0.2977, allocations: 6.236 MB / 456.6 MB, free: 12.81 MB / 366.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.00445/0.3021, allocations: 167.4 kB / 456.8 MB, free: 12.64 MB / 366.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.013/0.3151, allocations: 6.425 MB / 463.2 MB, free: 6.199 MB / 366.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.01134/0.3265, allocations: 3.498 MB / 466.7 MB, free: 2.688 MB / 366.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.005001/0.3315, allocations: 1.658 MB / 468.4 MB, free: 1.027 MB / 366.1 MB
Notification: Performance of NFFlatten.flatten: time 0.02016/0.3516, allocations: 12.96 MB / 481.3 MB, free: 4.039 MB / 382.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.009107/0.3607, allocations: 5.764 MB / 487.1 MB, free: 14.19 MB / 398.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.007506/0.3682, allocations: 3.762 MB / 490.9 MB, free: 10.41 MB / 398.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.009097/0.3773, allocations: 5.355 MB / 496.2 MB, free: 5.043 MB / 398.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.00303/0.3804, allocations: 0.7461 MB / 497 MB, free: 4.297 MB / 398.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.00518/0.3856, allocations: 1.74 MB / 498.7 MB, free: 2.555 MB / 398.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.008125/0.3937, allocations: 4.5 MB / 0.4914 GB, free: 14.04 MB / 414.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.01118/0.4049, allocations: 4.643 MB / 0.4959 GB, free: 9.375 MB / 414.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.02289/0.4277, allocations: 14.16 MB / 0.5098 GB, free: 11.16 MB / 430.1 MB
Notification: Performance of FrontEnd - DAE generated: time 7.264e-06/0.4277, allocations: 0 / 0.5098 GB, free: 11.16 MB / 430.1 MB
Notification: Performance of FrontEnd: time 1.573e-06/0.4278, allocations: 0 / 0.5098 GB, free: 11.16 MB / 430.1 MB
Notification: Performance of Transformations before backend: time 0.0006346/0.4284, allocations: 0 / 0.5098 GB, free: 11.16 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.03235/0.4607, allocations: 10.27 MB / 0.5198 GB, free: 0.7852 MB / 430.1 MB
Notification: Performance of prepare preOptimizeDAE: time 5.607e-05/0.4608, allocations: 8.031 kB / 0.5198 GB, free: 0.7773 MB / 430.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.04434/0.5051, allocations: 5.328 MB / 0.525 GB, free: 11.44 MB / 446.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.0216/0.5267, allocations: 8.13 MB / 0.5329 GB, free: 3.246 MB / 446.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0005963/0.5273, allocations: 448 kB / 0.5334 GB, free: 2.809 MB / 446.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.003103/0.5304, allocations: 0.6089 MB / 0.534 GB, free: 2.199 MB / 446.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.4396/0.97, allocations: 17.13 MB / 0.5507 GB, free: 87.31 MB / 446.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0002787/0.9703, allocations: 96.81 kB / 0.5508 GB, free: 87.28 MB / 446.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0008823/0.9712, allocations: 281.2 kB / 0.5511 GB, free: 87.13 MB / 446.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.003398/0.9746, allocations: 2.859 MB / 0.5538 GB, free: 86.18 MB / 446.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.02368/0.9983, allocations: 14.03 MB / 0.5675 GB, free: 73.44 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.07286/1.071, allocations: 69.79 MB / 0.6357 GB, free: 2.684 MB / 446.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.0206/1.092, allocations: 7.938 MB / 0.6435 GB, free: 10.59 MB / 462.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.006774/1.098, allocations: 4.345 MB / 0.6477 GB, free: 6.238 MB / 462.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.02325/1.122, allocations: 12.79 MB / 0.6602 GB, free: 9.379 MB / 478.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 6.807e-05/1.122, allocations: 76.42 kB / 0.6603 GB, free: 9.297 MB / 478.1 MB
Notification: Performance of pre-optimization done (n=293): time 5.801e-06/1.122, allocations: 0 / 0.6603 GB, free: 9.297 MB / 478.1 MB
Notification: Performance of matching and sorting (n=359): time 0.1935/1.315, allocations: 52.76 MB / 0.7118 GB, free: 4.957 MB / 0.5138 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.0002352/1.316, allocations: 394.2 kB / 0.7122 GB, free: 4.484 MB / 0.5138 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.01103/1.327, allocations: 7.282 MB / 0.7193 GB, free: 13.33 MB / 0.5294 GB
Notification: Performance of collectPreVariables (initialization): time 0.0009672/1.328, allocations: 81.64 kB / 0.7194 GB, free: 13.25 MB / 0.5294 GB
Notification: Performance of collectInitialEqns (initialization): time 0.004472/1.332, allocations: 5.385 MB / 0.7246 GB, free: 8.004 MB / 0.5294 GB
Notification: Performance of collectInitialBindings (initialization): time 0.001972/1.334, allocations: 1.387 MB / 0.726 GB, free: 6.605 MB / 0.5294 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.003077/1.337, allocations: 1.932 MB / 0.7279 GB, free: 4.66 MB / 0.5294 GB
Notification: Performance of setup shared object (initialization): time 0.0001274/1.337, allocations: 305.1 kB / 0.7281 GB, free: 4.359 MB / 0.5294 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.007739/1.345, allocations: 4.707 MB / 0.7327 GB, free: 15.64 MB / 0.545 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.01293/1.358, allocations: 9.542 MB / 0.7421 GB, free: 3.762 MB / 0.545 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.2353/1.593, allocations: 15 MB / 0.7567 GB, free: 171.1 MB / 0.545 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 0.0001592/1.593, allocations: 49.78 kB / 0.7568 GB, free: 171.1 MB / 0.545 GB
Notification: Performance of matching and sorting (n=1220) (initialization): time 0.03883/1.632, allocations: 20.4 MB / 0.7767 GB, free: 164.7 MB / 0.545 GB
Notification: Performance of prepare postOptimizeDAE: time 0.0001038/1.632, allocations: 75.91 kB / 0.7768 GB, free: 164.7 MB / 0.545 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0001662/1.632, allocations: 163.4 kB / 0.7769 GB, free: 164.7 MB / 0.545 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.02062/1.653, allocations: 7.336 MB / 0.7841 GB, free: 163.4 MB / 0.545 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.006413/1.659, allocations: 1.998 MB / 0.786 GB, free: 163.2 MB / 0.545 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.04077/1.7, allocations: 36.58 MB / 0.8218 GB, free: 126.9 MB / 0.545 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.008287/1.709, allocations: 0.6056 MB / 0.8223 GB, free: 126.3 MB / 0.545 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.001619/1.71, allocations: 0.5 MB / 0.8228 GB, free: 125.8 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.005642/1.716, allocations: 3.595 MB / 0.8263 GB, free: 122.3 MB / 0.545 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.001488/1.717, allocations: 0.6852 MB / 0.827 GB, free: 122 MB / 0.545 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.02488/1.742, allocations: 13.85 MB / 0.8405 GB, free: 108.1 MB / 0.545 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 5.131e-05/1.742, allocations: 36 kB / 0.8406 GB, free: 108.1 MB / 0.545 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 3.07e-05/1.742, allocations: 20 kB / 0.8406 GB, free: 108.1 MB / 0.545 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 5.824e-05/1.742, allocations: 15.94 kB / 0.8406 GB, free: 108 MB / 0.545 GB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.04402/1.786, allocations: 27.62 MB / 0.8676 GB, free: 80.12 MB / 0.545 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 5.538e-05/1.786, allocations: 8 kB / 0.8676 GB, free: 80.11 MB / 0.545 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.002245/1.789, allocations: 471.3 kB / 0.868 GB, free: 79.65 MB / 0.545 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.01897/1.808, allocations: 6.964 MB / 0.8748 GB, free: 72.68 MB / 0.545 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0009401/1.809, allocations: 68.69 kB / 0.8749 GB, free: 72.61 MB / 0.545 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.0391/1.848, allocations: 35.35 MB / 0.9094 GB, free: 37.07 MB / 0.545 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 6.502e-06/1.848, allocations: 11.94 kB / 0.9094 GB, free: 37.06 MB / 0.545 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.03202/1.88, allocations: 19.66 MB / 0.9286 GB, free: 17.25 MB / 0.545 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.00207/1.882, allocations: 0.7357 MB / 0.9293 GB, free: 16.5 MB / 0.545 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.00149/1.883, allocations: 64 kB / 0.9294 GB, free: 16.44 MB / 0.545 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.00382/1.887, allocations: 330.9 kB / 0.9297 GB, free: 16.12 MB / 0.545 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.001201/1.888, allocations: 254.8 kB / 0.93 GB, free: 15.87 MB / 0.545 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0003046/1.889, allocations: 92.75 kB / 0.9301 GB, free: 15.78 MB / 0.545 GB
Notification: Performance of sorting global known variables: time 0.006981/1.895, allocations: 4.646 MB / 0.9346 GB, free: 11.16 MB / 0.545 GB
Notification: Performance of sort global known variables: time 1.9e-07/1.895, allocations: 0 / 0.9346 GB, free: 11.16 MB / 0.545 GB
Notification: Performance of remove unused functions: time 0.01034/1.906, allocations: 2.199 MB / 0.9367 GB, free: 8.969 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.0008911/1.907, allocations: 227.6 kB / 0.937 GB, free: 8.754 MB / 0.545 GB
Notification: Performance of simCode: created initialization part: time 0.01737/1.924, allocations: 11.51 MB / 0.9482 GB, free: 13.21 MB / 0.5607 GB
Notification: Performance of simCode: created event and clocks part: time 1.214e-05/1.924, allocations: 4.188 kB / 0.9482 GB, free: 13.2 MB / 0.5607 GB
Notification: Performance of simCode: created simulation system equations: time 0.2297/2.154, allocations: 4.895 MB / 0.953 GB, free: 195.1 MB / 0.5607 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.007258/2.161, allocations: 1.025 MB / 0.954 GB, free: 195 MB / 0.5607 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.03842/2.199, allocations: 20.75 MB / 0.9742 GB, free: 189 MB / 0.5607 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.008755/2.208, allocations: 5.731 MB / 0.9798 GB, free: 187.1 MB / 0.5607 GB
Notification: Performance of simCode: alias equations: time 0.008791/2.217, allocations: 2.697 MB / 0.9825 GB, free: 187.1 MB / 0.5607 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001711/2.219, allocations: 399.4 kB / 0.9829 GB, free: 186.9 MB / 0.5607 GB
Notification: Performance of SimCode: time 1.283e-06/2.219, allocations: 0 / 0.9829 GB, free: 186.9 MB / 0.5607 GB
Notification: Performance of Templates: time 0.1462/2.365, allocations: 98.72 MB / 1.079 GB, free: 91.15 MB / 0.5607 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.327918818220496]