Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR.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.002441/0.002441, allocations: 91.61 kB / 20.96 MB, free: 3.461 MB / 18.57 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.00279/0.00279, allocations: 161.3 kB / 24.27 MB, free: 152 kB / 18.57 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.591/1.591, allocations: 177.1 MB / 204.6 MB, free: 5.582 MB / 186.7 MB
"
[Timeout remaining time 178]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest 4.0.0+maint.om/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest 4.0.0+maint.om/package.mo): time 0.3768/0.3768, allocations: 32.8 MB / 293.9 MB, free: 1.215 MB / 266.7 MB
"
[Timeout remaining time 179]
Using package ModelicaTest with version 4.0.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest 4.0.0+maint.om/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(ModelicaTest.MultiBody.FourbarVariants.JointUSR,tolerance=1e-06,outputFormat="mat",numberOfIntervals=5002,variableFilter="time|j2.s|j2.v",fileNamePrefix="ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR")
translateModel(ModelicaTest.MultiBody.FourbarVariants.JointUSR,tolerance=1e-06,outputFormat="mat",numberOfIntervals=5002,variableFilter="time|j2.s|j2.v",fileNamePrefix="ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 1.393e-06/1.393e-06, allocations: 0 / 375.3 MB, free: 5.004 MB / 346.7 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 3.198e-05/3.337e-05, allocations: 6.25 kB / 375.3 MB, free: 4.996 MB / 346.7 MB
Notification: Performance of NFInst.instantiate(ModelicaTest.MultiBody.FourbarVariants.JointUSR): time 0.02416/0.0242, allocations: 16.9 MB / 392.2 MB, free: 4.016 MB / 362.7 MB
Notification: Performance of NFInst.instExpressions: time 0.01431/0.03851, allocations: 5.581 MB / 397.7 MB, free: 14.41 MB / 378.7 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003499/0.04201, allocations: 131.4 kB / 397.9 MB, free: 14.29 MB / 378.7 MB
Notification: Performance of NFTyping.typeComponents: time 0.01149/0.0535, allocations: 4.902 MB / 402.8 MB, free: 9.367 MB / 378.7 MB
Notification: Performance of NFTyping.typeBindings: time 0.0096/0.0631, allocations: 3.18 MB / 405.9 MB, free: 6.172 MB / 378.7 MB
Notification: Performance of NFTyping.typeClassSections: time 0.004336/0.06743, allocations: 1.696 MB / 407.6 MB, free: 4.473 MB / 378.7 MB
Notification: Performance of NFFlatten.flatten: time 0.01634/0.08378, allocations: 10.31 MB / 418 MB, free: 10.14 MB / 394.7 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.01107/0.09485, allocations: 6.446 MB / 424.4 MB, free: 3.621 MB / 394.7 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.01071/0.1056, allocations: 4.701 MB / 429.1 MB, free: 14.91 MB / 410.7 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.009947/0.1155, allocations: 4.981 MB / 434.1 MB, free: 9.918 MB / 410.7 MB
Notification: Performance of NFPackage.collectConstants: time 0.002554/0.1181, allocations: 0.6758 MB / 434.8 MB, free: 9.242 MB / 410.7 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.005661/0.1237, allocations: 1.834 MB / 436.6 MB, free: 7.406 MB / 410.7 MB
Notification: Performance of NFScalarize.scalarize: time 0.006671/0.1304, allocations: 3.994 MB / 440.6 MB, free: 3.402 MB / 410.7 MB
Notification: Performance of NFVerifyModel.verify: time 0.006552/0.1369, allocations: 2.489 MB / 443.1 MB, free: 0.9062 MB / 410.7 MB
Notification: Performance of NFConvertDAE.convert: time 0.1898/0.3267, allocations: 13.8 MB / 456.9 MB, free: 64.39 MB / 410.7 MB
Notification: Performance of FrontEnd - DAE generated: time 6.713e-06/0.3267, allocations: 0 / 456.9 MB, free: 64.39 MB / 410.7 MB
Notification: Performance of FrontEnd: time 1.583e-06/0.3267, allocations: 0 / 456.9 MB, free: 64.39 MB / 410.7 MB
Notification: Performance of Transformations before backend: time 0.0004908/0.3272, allocations: 0.5625 kB / 456.9 MB, free: 64.39 MB / 410.7 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 2782
 * Number of variables: 2782
Notification: Performance of Generate backend data structure: time 0.02553/0.3527, allocations: 10.7 MB / 467.6 MB, free: 60.92 MB / 410.7 MB
Notification: Performance of prepare preOptimizeDAE: time 4.216e-05/0.3528, allocations: 13.25 kB / 467.6 MB, free: 60.92 MB / 410.7 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.01956/0.3723, allocations: 5.219 MB / 472.8 MB, free: 60.3 MB / 410.7 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.01334/0.3857, allocations: 4.551 MB / 477.4 MB, free: 58.5 MB / 410.7 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0004346/0.3861, allocations: 435.7 kB / 477.8 MB, free: 58.36 MB / 410.7 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.003238/0.3893, allocations: 0.6023 MB / 478.4 MB, free: 58.21 MB / 410.7 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.03782/0.4272, allocations: 13.13 MB / 491.5 MB, free: 51.56 MB / 410.7 MB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0002841/0.4275, allocations: 74.12 kB / 491.6 MB, free: 51.55 MB / 410.7 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.001224/0.4287, allocations: 268.7 kB / 491.9 MB, free: 51.43 MB / 410.7 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.005033/0.4337, allocations: 3.712 MB / 495.6 MB, free: 50.79 MB / 410.7 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.0274/0.4611, allocations: 7.95 MB / 0.4917 GB, free: 49.84 MB / 410.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.1229/0.584, allocations: 91.6 MB / 0.5812 GB, free: 9.578 MB / 458.7 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.01773/0.6017, allocations: 4.052 MB / 0.5851 GB, free: 5.488 MB / 458.7 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.004079/0.6058, allocations: 1.408 MB / 0.5865 GB, free: 4.062 MB / 458.7 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.03341/0.6392, allocations: 10.56 MB / 0.5968 GB, free: 9.613 MB / 474.7 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 8.203e-05/0.6393, allocations: 70.33 kB / 0.5969 GB, free: 9.535 MB / 474.7 MB
Notification: Performance of pre-optimization done (n=335): time 8.115e-06/0.6393, allocations: 0 / 0.5969 GB, free: 9.535 MB / 474.7 MB
Notification: Performance of matching and sorting (n=419): time 0.2852/0.9245, allocations: 24.22 MB / 0.6205 GB, free: 143.7 MB / 474.7 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 9.492e-05/0.9246, allocations: 195.6 kB / 0.6207 GB, free: 143.5 MB / 474.7 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.01146/0.9361, allocations: 7.063 MB / 0.6276 GB, free: 142.5 MB / 474.7 MB
Notification: Performance of collectPreVariables (initialization): time 0.001323/0.9374, allocations: 84.33 kB / 0.6277 GB, free: 142.5 MB / 474.7 MB
Notification: Performance of collectInitialEqns (initialization): time 0.004918/0.9423, allocations: 6.148 MB / 0.6337 GB, free: 139 MB / 474.7 MB
Notification: Performance of collectInitialBindings (initialization): time 0.002669/0.945, allocations: 1.76 MB / 0.6354 GB, free: 138 MB / 474.7 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.005166/0.9502, allocations: 2.675 MB / 0.638 GB, free: 137.5 MB / 474.7 MB
Notification: Performance of setup shared object (initialization): time 7.785e-05/0.9502, allocations: 478.7 kB / 0.6385 GB, free: 137 MB / 474.7 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.005258/0.9555, allocations: 1.634 MB / 0.6401 GB, free: 136.7 MB / 474.7 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.01173/0.9672, allocations: 10.79 MB / 0.6506 GB, free: 124.5 MB / 474.7 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.01491/0.9821, allocations: 13.77 MB / 0.6641 GB, free: 110.6 MB / 474.7 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 0.0004431/0.9826, allocations: 59.84 kB / 0.6641 GB, free: 110.6 MB / 474.7 MB
Notification: Performance of matching and sorting (n=1413) (initialization): time 0.03185/1.014, allocations: 11.05 MB / 0.6749 GB, free: 106.9 MB / 474.7 MB
Notification: Performance of prepare postOptimizeDAE: time 0.0005537/1.015, allocations: 95.84 kB / 0.675 GB, free: 106.9 MB / 474.7 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0005816/1.016, allocations: 205.7 kB / 0.6752 GB, free: 106.9 MB / 474.7 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.009252/1.025, allocations: 2.01 MB / 0.6772 GB, free: 105.7 MB / 474.7 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.009529/1.034, allocations: 2.456 MB / 0.6796 GB, free: 103.2 MB / 474.7 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.01539/1.05, allocations: 7.096 MB / 0.6865 GB, free: 96.04 MB / 474.7 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.009873/1.06, allocations: 0.7119 MB / 0.6872 GB, free: 95.34 MB / 474.7 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.002386/1.062, allocations: 0.5937 MB / 0.6878 GB, free: 94.74 MB / 474.7 MB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 943
 * Number of states: 0 ()
 * Number of discrete variables: 49 (jointUSR.revolute.positiveBranch,Body3.sphereColor[3],Body3.sphereColor[2],Body3.sphereColor[1],Body2.sphereColor[3],Body2.sphereColor[2],Body2.sphereColor[1],Body1.sphereColor[3],Body1.sphereColor[2],Body1.sphereColor[1],jointUSR.rod1Color[3],jointUSR.rod1Color[2],jointUSR.rod1Color[1],jointUSR.cylinderColor[3],jointUSR.cylinderColor[2],jointUSR.cylinderColor[1],jointUSR.sphereColor[3],jointUSR.sphereColor[2],jointUSR.sphereColor[1],jointUSR.revoluteColor[3],jointUSR.revoluteColor[2],jointUSR.revoluteColor[1],fixedFrame.color_x[3],fixedFrame.color_x[2],fixedFrame.color_x[1],b3.color[3],b3.color[2],b3.color[1],b2.color[3],b2.color[2],b2.color[1],b2.body.sphereColor[3],b2.body.sphereColor[2],b2.body.sphereColor[1],j2.boxColor[3],j2.boxColor[2],j2.boxColor[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 (1312):
 * Single equations (assignments): 1305
 * Array equations: 6
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 1
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 1 system
   {(2,52,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of prepare postOptimizeDAE: time 0.00613/1.068, allocations: 1.169 MB / 0.6889 GB, free: 93.55 MB / 474.7 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.00185/1.07, allocations: 0.6798 MB / 0.6896 GB, free: 92.87 MB / 474.7 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.01328/1.083, allocations: 4.671 MB / 0.6941 GB, free: 88.15 MB / 474.7 MB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 9.83e-05/1.083, allocations: 61.7 kB / 0.6942 GB, free: 88.09 MB / 474.7 MB
Notification: Performance of postOpt constantLinearSystem (simulation): time 2.462e-05/1.083, allocations: 8 kB / 0.6942 GB, free: 88.09 MB / 474.7 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 7.286e-05/1.083, allocations: 23.92 kB / 0.6942 GB, free: 88.06 MB / 474.7 MB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.03492/1.118, allocations: 14.64 MB / 0.7085 GB, free: 73.21 MB / 474.7 MB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 2.716e-05/1.118, allocations: 12 kB / 0.7085 GB, free: 73.2 MB / 474.7 MB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.002844/1.121, allocations: 0.6247 MB / 0.7091 GB, free: 72.58 MB / 474.7 MB
Notification: Performance of postOpt tearingSystem (simulation): time 0.007405/1.129, allocations: 1.522 MB / 0.7106 GB, free: 71.06 MB / 474.7 MB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0007059/1.129, allocations: 77.75 kB / 0.7107 GB, free: 70.98 MB / 474.7 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.01178/1.141, allocations: 6.039 MB / 0.7166 GB, free: 64.84 MB / 474.7 MB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 8.686e-06/1.141, allocations: 23.88 kB / 0.7166 GB, free: 64.81 MB / 474.7 MB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.01571/1.157, allocations: 6.769 MB / 0.7232 GB, free: 57.71 MB / 474.7 MB
Notification: Performance of postOpt removeConstants (simulation): time 0.002285/1.159, allocations: 0.5741 MB / 0.7238 GB, free: 57.13 MB / 474.7 MB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.001422/1.161, allocations: 87.02 kB / 0.7239 GB, free: 57.05 MB / 474.7 MB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.003431/1.164, allocations: 279.6 kB / 0.7241 GB, free: 56.78 MB / 474.7 MB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.000762/1.165, allocations: 277.5 kB / 0.7244 GB, free: 56.5 MB / 474.7 MB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.000262/1.165, allocations: 116 kB / 0.7245 GB, free: 56.39 MB / 474.7 MB
Notification: Performance of sorting global known variables: time 0.004923/1.17, allocations: 2.896 MB / 0.7273 GB, free: 53.52 MB / 474.7 MB
Notification: Performance of sort global known variables: time 2.8e-07/1.17, allocations: 0 / 0.7273 GB, free: 53.52 MB / 474.7 MB
Notification: Performance of remove unused functions: time 0.0104/1.18, allocations: 2.123 MB / 0.7294 GB, free: 51.4 MB / 474.7 MB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 55
 * Number of states: 2 (j2.s,j2.v)
 * 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 (331):
 * Single equations (assignments): 324
 * Array equations: 6
 * Algorithm blocks: 0
 * Record equations: 0
 * When equations: 0
 * If-equations: 0
 * Equation systems (not torn): 0
 * Torn equation systems: 1
 * Mixed (continuous/discrete) equation systems: 0
Notification: Torn system details for strict tearing set:
 * Linear torn systems (#iteration vars, #inner vars, density): 1 system
   {(2,42,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of Backend phase and start with SimCode phase: time 0.0009984/1.181, allocations: 311.1 kB / 0.7297 GB, free: 51.1 MB / 474.7 MB
Notification: Performance of simCode: created initialization part: time 0.01237/1.194, allocations: 6.582 MB / 0.7361 GB, free: 44.52 MB / 474.7 MB
Notification: Performance of simCode: created event and clocks part: time 1.578e-05/1.194, allocations: 4 kB / 0.7361 GB, free: 44.52 MB / 474.7 MB
Notification: Performance of simCode: created simulation system equations: time 0.003519/1.197, allocations: 2.022 MB / 0.7381 GB, free: 42.46 MB / 474.7 MB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.004325/1.202, allocations: 0.7247 MB / 0.7388 GB, free: 41.77 MB / 474.7 MB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.02387/1.225, allocations: 14.95 MB / 0.7534 GB, free: 26.48 MB / 474.7 MB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.005508/1.231, allocations: 4.628 MB / 0.7579 GB, free: 21.82 MB / 474.7 MB
Notification: Performance of simCode: alias equations: time 0.00635/1.237, allocations: 2.741 MB / 0.7606 GB, free: 19.07 MB / 474.7 MB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001446/1.239, allocations: 404.4 kB / 0.761 GB, free: 18.68 MB / 474.7 MB
Notification: Performance of SimCode: time 1.232e-06/1.239, allocations: 0 / 0.761 GB, free: 18.68 MB / 474.7 MB
Notification: Performance of Templates: time 0.2895/1.528, allocations: 65.8 MB / 0.8253 GB, free: 102.7 MB / 474.7 MB
"
[Timeout remaining time 658]
make -j1 -f ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR.makefile [Timeout 660]
(rm -f ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe ; mkfifo ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe ; head -c 1048576 < ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe >> ../files/ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR.sim & ./ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR -abortSlowSimulation -alarm=240  -emit_protected -lv LOG_STATS > ModelicaTest_4.0.0_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe 2>&1) [Timeout 240]
[Calling os._exit(0), Time elapsed: 9.096452689031139]