Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR.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.001841/0.001841, allocations: 79.05 kB / 20.49 MB, free: 1.387 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.001659/0.001659, allocations: 162.8 kB / 23.74 MB, free: 4.578 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.506/1.506, allocations: 177.1 MB / 204 MB, free: 9.258 MB / 190.1 MB
"
[Timeout remaining time 178]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest trunk/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest trunk/package.mo): time 0.2387/0.2387, allocations: 34.26 MB / 294.7 MB, free: 14.64 MB / 286.1 MB
"
[Timeout remaining time 180]
Using package ModelicaTest with version trunk (/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest trunk/package.mo)
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(ModelicaTest.MultiBody.FourbarVariants.JointUSR,tolerance=1e-06,outputFormat="mat",numberOfIntervals=5002,variableFilter="time|j2.s|j2.v",fileNamePrefix="ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR")
translateModel(ModelicaTest.MultiBody.FourbarVariants.JointUSR,tolerance=1e-06,outputFormat="mat",numberOfIntervals=5002,variableFilter="time|j2.s|j2.v",fileNamePrefix="ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR") [Timeout 660]
"Notification: Performance of FrontEnd - loaded program: time 0.002474/0.002474, allocations: 79.88 kB / 442.4 MB, free: 5.539 MB / 366.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.2997/0.3022, allocations: 66.06 MB / 0.4965 GB, free: 1.738 MB / 398.1 MB
Notification: Performance of NFInst.instantiate(ModelicaTest.MultiBody.FourbarVariants.JointUSR): time 0.02105/0.3233, allocations: 15.32 MB / 0.5115 GB, free: 2.355 MB / 414.1 MB
Notification: Performance of NFInst.instExpressions: time 0.01419/0.3375, allocations: 5.457 MB / 0.5168 GB, free: 12.88 MB / 430.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003053/0.3405, allocations: 127.4 kB / 0.5169 GB, free: 12.76 MB / 430.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.01047/0.351, allocations: 4.684 MB / 0.5215 GB, free: 8.059 MB / 430.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.009239/0.3602, allocations: 3.117 MB / 0.5246 GB, free: 4.93 MB / 430.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.004606/0.3648, allocations: 1.661 MB / 0.5262 GB, free: 3.266 MB / 430.1 MB
Notification: Performance of NFFlatten.flatten: time 0.01405/0.3789, allocations: 8.943 MB / 0.5349 GB, free: 10.31 MB / 446.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.007986/0.3869, allocations: 5.223 MB / 0.54 GB, free: 5.008 MB / 446.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.008754/0.3956, allocations: 4.239 MB / 0.5442 GB, free: 0.7578 MB / 446.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.007414/0.403, allocations: 4.365 MB / 0.5484 GB, free: 12.38 MB / 462.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.002287/0.4053, allocations: 0.6602 MB / 0.5491 GB, free: 11.72 MB / 462.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.004516/0.4098, allocations: 1.728 MB / 0.5507 GB, free: 9.988 MB / 462.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.005323/0.4152, allocations: 3.79 MB / 0.5544 GB, free: 6.188 MB / 462.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.006369/0.4215, allocations: 3.115 MB / 0.5575 GB, free: 3.055 MB / 462.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.01949/0.441, allocations: 13.62 MB / 0.5708 GB, free: 5.383 MB / 478.1 MB
Notification: Performance of FrontEnd - DAE generated: time 6.122e-06/0.441, allocations: 4 kB / 0.5708 GB, free: 5.379 MB / 478.1 MB
Notification: Performance of FrontEnd: time 1.834e-06/0.441, allocations: 0 / 0.5708 GB, free: 5.379 MB / 478.1 MB
Notification: Performance of Transformations before backend: time 0.0005171/0.4416, allocations: 0 / 0.5708 GB, free: 5.379 MB / 478.1 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.02511/0.4667, allocations: 9.135 MB / 0.5797 GB, free: 12.16 MB / 494.1 MB
Notification: Performance of prepare preOptimizeDAE: time 4.76e-05/0.4667, allocations: 8.031 kB / 0.5797 GB, free: 12.15 MB / 494.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.02004/0.4868, allocations: 4.453 MB / 0.5841 GB, free: 7.688 MB / 494.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.01496/0.5017, allocations: 5.033 MB / 0.589 GB, free: 2.559 MB / 494.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.000564/0.5023, allocations: 426.9 kB / 0.5894 GB, free: 2.141 MB / 494.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.00293/0.5052, allocations: 0.6011 MB / 0.59 GB, free: 1.539 MB / 494.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.04996/0.5552, allocations: 20.75 MB / 0.6102 GB, free: 11.62 MB / 0.5137 GB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0004579/0.5556, allocations: 79.33 kB / 0.6103 GB, free: 11.55 MB / 0.5137 GB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.002378/0.558, allocations: 275.7 kB / 0.6106 GB, free: 11.28 MB / 0.5137 GB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.006686/0.5647, allocations: 3.726 MB / 0.6142 GB, free: 7.543 MB / 0.5137 GB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.04531/0.61, allocations: 18.21 MB / 0.632 GB, free: 5.316 MB / 0.5294 GB
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.6383/1.248, allocations: 69.38 MB / 0.6998 GB, free: 62.6 MB / 0.5294 GB
Notification: Performance of preOpt comSubExp (simulation): time 0.01723/1.266, allocations: 6.514 MB / 0.7061 GB, free: 56.09 MB / 0.5294 GB
Notification: Performance of preOpt resolveLoops (simulation): time 0.005339/1.271, allocations: 3.826 MB / 0.7099 GB, free: 52.25 MB / 0.5294 GB
Notification: Performance of preOpt evalFunc (simulation): time 0.0342/1.305, allocations: 14.86 MB / 0.7244 GB, free: 37.63 MB / 0.5294 GB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 6.182e-05/1.305, allocations: 68.58 kB / 0.7244 GB, free: 37.55 MB / 0.5294 GB
Notification: Performance of pre-optimization done (n=335): time 1.139e-05/1.305, allocations: 0 / 0.7244 GB, free: 37.55 MB / 0.5294 GB
Notification: Performance of matching and sorting (n=419): time 0.1387/1.444, allocations: 35.9 MB / 0.7595 GB, free: 2.059 MB / 0.5294 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.0001091/1.444, allocations: 200.9 kB / 0.7597 GB, free: 1.824 MB / 0.5294 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.02/1.464, allocations: 6.182 MB / 0.7657 GB, free: 11.91 MB / 0.545 GB
Notification: Performance of collectPreVariables (initialization): time 0.00127/1.465, allocations: 89.61 kB / 0.7658 GB, free: 11.82 MB / 0.545 GB
Notification: Performance of collectInitialEqns (initialization): time 0.008984/1.474, allocations: 5.611 MB / 0.7713 GB, free: 6.359 MB / 0.545 GB
Notification: Performance of collectInitialBindings (initialization): time 0.00408/1.478, allocations: 1.616 MB / 0.7729 GB, free: 4.73 MB / 0.545 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.01011/1.488, allocations: 2.14 MB / 0.775 GB, free: 2.578 MB / 0.545 GB
Notification: Performance of setup shared object (initialization): time 0.0002259/1.489, allocations: 305.1 kB / 0.7752 GB, free: 2.277 MB / 0.545 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.01634/1.505, allocations: 4.347 MB / 0.7795 GB, free: 13.92 MB / 0.5607 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.02647/1.531, allocations: 10.31 MB / 0.7896 GB, free: 0.7148 MB / 0.5607 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.04141/1.573, allocations: 15.69 MB / 0.8049 GB, free: 14.1 MB / 0.5919 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 0.0003321/1.573, allocations: 60 kB / 0.8049 GB, free: 14.04 MB / 0.5919 GB
Notification: Performance of matching and sorting (n=1413) (initialization): time 0.06503/1.638, allocations: 16.33 MB / 0.8209 GB, free: 13.68 MB / 0.6075 GB
Notification: Performance of prepare postOptimizeDAE: time 0.0005174/1.639, allocations: 96 kB / 0.821 GB, free: 13.59 MB / 0.6075 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0006471/1.639, allocations: 207.9 kB / 0.8212 GB, free: 13.39 MB / 0.6075 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.01241/1.652, allocations: 2.366 MB / 0.8235 GB, free: 11.02 MB / 0.6075 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.01041/1.662, allocations: 2.48 MB / 0.8259 GB, free: 8.531 MB / 0.6075 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.02386/1.686, allocations: 12.44 MB / 0.8381 GB, free: 11.97 MB / 0.6232 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.00861/1.695, allocations: 0.6322 MB / 0.8387 GB, free: 11.34 MB / 0.6232 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.002002/1.697, allocations: 0.6014 MB / 0.8393 GB, free: 10.74 MB / 0.6232 GB
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.01006/1.707, allocations: 3.774 MB / 0.8429 GB, free: 6.953 MB / 0.6232 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.002274/1.709, allocations: 0.5743 MB / 0.8435 GB, free: 6.375 MB / 0.6232 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.02497/1.734, allocations: 8.251 MB / 0.8516 GB, free: 14.07 MB / 0.6388 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 0.0001165/1.734, allocations: 63.98 kB / 0.8516 GB, free: 14.01 MB / 0.6388 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 4.186e-05/1.734, allocations: 12 kB / 0.8516 GB, free: 14 MB / 0.6388 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 8.784e-05/1.734, allocations: 19.92 kB / 0.8517 GB, free: 13.98 MB / 0.6388 GB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.04651/1.781, allocations: 16.12 MB / 0.8674 GB, free: 13.57 MB / 0.6544 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 5.724e-05/1.781, allocations: 15.98 kB / 0.8674 GB, free: 13.55 MB / 0.6544 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.003521/1.784, allocations: 0.6242 MB / 0.868 GB, free: 12.93 MB / 0.6544 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.007756/1.792, allocations: 1.811 MB / 0.8698 GB, free: 11.11 MB / 0.6544 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0007436/1.793, allocations: 75.98 kB / 0.8699 GB, free: 11.04 MB / 0.6544 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.02112/1.814, allocations: 10.56 MB / 0.8802 GB, free: 380 kB / 0.6544 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 1.806e-05/1.814, allocations: 15.94 kB / 0.8802 GB, free: 364 kB / 0.6544 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.02885/1.843, allocations: 12.42 MB / 0.8923 GB, free: 3.656 MB / 0.67 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.002326/1.845, allocations: 0.5233 MB / 0.8928 GB, free: 3.129 MB / 0.67 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.002254/1.847, allocations: 83.97 kB / 0.8929 GB, free: 3.047 MB / 0.67 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.004602/1.852, allocations: 219.7 kB / 0.8931 GB, free: 2.832 MB / 0.67 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.00129/1.853, allocations: 285.5 kB / 0.8934 GB, free: 2.551 MB / 0.67 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0007856/1.854, allocations: 112 kB / 0.8935 GB, free: 2.441 MB / 0.67 GB
Notification: Performance of sorting global known variables: time 0.3195/2.174, allocations: 3.567 MB / 0.897 GB, free: 236.8 MB / 0.67 GB
Notification: Performance of sort global known variables: time 2.3e-07/2.174, allocations: 0 / 0.897 GB, free: 236.8 MB / 0.67 GB
Notification: Performance of remove unused functions: time 0.01235/2.186, allocations: 1.91 MB / 0.8989 GB, free: 236.8 MB / 0.67 GB
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.001487/2.187, allocations: 285.1 kB / 0.8991 GB, free: 236.7 MB / 0.67 GB
Notification: Performance of simCode: created initialization part: time 0.01781/2.205, allocations: 9.699 MB / 0.9086 GB, free: 234.6 MB / 0.67 GB
Notification: Performance of simCode: created event and clocks part: time 2.095e-05/2.205, allocations: 3.875 kB / 0.9086 GB, free: 234.6 MB / 0.67 GB
Notification: Performance of simCode: created simulation system equations: time 0.005187/2.21, allocations: 3.12 MB / 0.9116 GB, free: 233.4 MB / 0.67 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.005993/2.216, allocations: 0.6764 MB / 0.9123 GB, free: 233.1 MB / 0.67 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.02894/2.245, allocations: 18.03 MB / 0.9299 GB, free: 224.4 MB / 0.67 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.006269/2.252, allocations: 5.11 MB / 0.9349 GB, free: 220.6 MB / 0.67 GB
Notification: Performance of simCode: alias equations: time 0.007044/2.259, allocations: 3.257 MB / 0.9381 GB, free: 218.6 MB / 0.67 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001373/2.26, allocations: 394.7 kB / 0.9385 GB, free: 218.2 MB / 0.67 GB
Notification: Performance of SimCode: time 1.162e-06/2.26, allocations: 0 / 0.9385 GB, free: 218.2 MB / 0.67 GB
Notification: Performance of Templates: time 0.104/2.364, allocations: 62.66 MB / 0.9997 GB, free: 157.8 MB / 0.67 GB
"
[Timeout remaining time 658]
make -j1 -f ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR.makefile [Timeout 660]
(rm -f ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe ; mkfifo ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe ; head -c 1048576 < ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe >> ../files/ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR.sim & ./ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR  -abortSlowSimulation -alarm=480  -emit_protected -lv LOG_STATS > ModelicaTest_trunk_ModelicaTest.MultiBody.FourbarVariants.JointUSR.pipe 2>&1) [Timeout 480]
[Calling os._exit(0), Time elapsed: 9.653675802052021]
Failed to read output from testmodel.py, exit status != 0:
['time', 'j2.s', 'j2.v']
2.374671122059226 2.385658383 1.941789423
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7fcf24caafe0>