Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.ForceWithTwoMasses.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.001523/0.001523, allocations: 118.6 kB / 18.5 MB, free: 4.566 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.001949/0.001949, allocations: 214.6 kB / 21.46 MB, free: 1.605 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.439/1.439, allocations: 230.2 MB / 254.5 MB, free: 15.4 MB / 206.1 MB
"
[Timeout remaining time 178]
loadFile("/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest 4.1.0-beta.om/package.mo", uses=false) [Timeout 180]
"Notification: Performance of loadFile(/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest 4.1.0-beta.om/package.mo): time 0.227/0.227, allocations: 46.88 MB / 357.4 MB, free: 10.55 MB / 286.1 MB
"
[Timeout remaining time 180]
Using package ModelicaTest with version 4.1.0 (/home/hudson/saved_omc/libraries/.openmodelica/libraries/ModelicaTest 4.1.0-beta.om/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: "" <> buildModelFMU(ModelicaTest.MultiBody.Forces.ForceWithTwoMasses,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_ForceWithTwoMasses",fmuType="me",version="2.0",platforms={"static"})
"" <> buildModelFMU(ModelicaTest.MultiBody.Forces.ForceWithTwoMasses,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_ForceWithTwoMasses",fmuType="me",version="2.0",platforms={"static"}) [Timeout 660]
"Warning: Requested package Modelica of version 4.1.0, but this package was already loaded with version trunk. OpenModelica cannot reason about compatibility between the two packages since they are not semantic versions.
Notification: Performance of FrontEnd - loaded program: time 0.002329/0.002329, allocations: 77.62 kB / 0.4912 GB, free: 26.88 MB / 366.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.1146/0.1169, allocations: 65.97 MB / 0.5557 GB, free: 9.172 MB / 414.1 MB
Notification: Performance of NFInst.instantiate(ModelicaTest.MultiBody.Forces.ForceWithTwoMasses): time 0.01336/0.1303, allocations: 10.41 MB / 0.5658 GB, free: 14.71 MB / 430.1 MB
Notification: Performance of NFInst.instExpressions: time 0.009235/0.1395, allocations: 3.907 MB / 0.5696 GB, free: 10.79 MB / 430.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.001787/0.1413, allocations: 59.81 kB / 0.5697 GB, free: 10.73 MB / 430.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.004717/0.146, allocations: 2.098 MB / 0.5717 GB, free: 8.621 MB / 430.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.004914/0.1509, allocations: 1.704 MB / 0.5734 GB, free: 6.91 MB / 430.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.002086/0.153, allocations: 0.7018 MB / 0.5741 GB, free: 6.207 MB / 430.1 MB
Notification: Performance of NFFlatten.flatten: time 0.007105/0.1601, allocations: 3.996 MB / 0.578 GB, free: 2.203 MB / 430.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.003932/0.1641, allocations: 2.223 MB / 0.5802 GB, free: 15.93 MB / 446.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.002678/0.1667, allocations: 1.304 MB / 0.5814 GB, free: 14.62 MB / 446.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.003401/0.1701, allocations: 1.998 MB / 0.5834 GB, free: 12.62 MB / 446.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.001088/0.1712, allocations: 264 kB / 0.5836 GB, free: 12.36 MB / 446.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.002936/0.1742, allocations: 1.217 MB / 0.5848 GB, free: 11.14 MB / 446.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.002533/0.1767, allocations: 1.706 MB / 0.5865 GB, free: 9.43 MB / 446.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.003873/0.1806, allocations: 1.957 MB / 0.5884 GB, free: 7.461 MB / 446.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.009564/0.1901, allocations: 6.346 MB / 0.5946 GB, free: 1.09 MB / 446.1 MB
Notification: Performance of FrontEnd - DAE generated: time 8.015e-06/0.1901, allocations: 4 kB / 0.5946 GB, free: 1.086 MB / 446.1 MB
Notification: Performance of FrontEnd: time 1.834e-06/0.1901, allocations: 0 / 0.5946 GB, free: 1.086 MB / 446.1 MB
Notification: Performance of Transformations before backend: time 0.0002413/0.1904, allocations: 0 / 0.5946 GB, free: 1.086 MB / 446.1 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 1319
 * Number of variables: 1319
Notification: Performance of Generate backend data structure: time 0.01227/0.2027, allocations: 4.445 MB / 0.5989 GB, free: 12.56 MB / 462.1 MB
Notification: Performance of prepare preOptimizeDAE: time 4.912e-05/0.2027, allocations: 8.031 kB / 0.599 GB, free: 12.55 MB / 462.1 MB
Notification: Performance of preOpt introduceOutputAliases (simulation): time 0.001681/0.2044, allocations: 0.6288 MB / 0.5996 GB, free: 11.91 MB / 462.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.08115/0.2855, allocations: 7.048 MB / 0.6064 GB, free: 4.855 MB / 462.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.007381/0.2929, allocations: 2.641 MB / 0.609 GB, free: 2.152 MB / 462.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0002209/0.2931, allocations: 193.3 kB / 0.6092 GB, free: 1.961 MB / 462.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.001179/0.2943, allocations: 279.7 kB / 0.6095 GB, free: 1.688 MB / 462.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.2523/0.5466, allocations: 8.52 MB / 0.6178 GB, free: 44.07 MB / 462.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0002652/0.5468, allocations: 40.81 kB / 0.6178 GB, free: 44.05 MB / 462.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0009022/0.5477, allocations: 127.8 kB / 0.618 GB, free: 44 MB / 462.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.003401/0.5511, allocations: 1.738 MB / 0.6197 GB, free: 43.71 MB / 462.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.01631/0.5675, allocations: 7.166 MB / 0.6267 GB, free: 41.52 MB / 462.1 MB
Notification: Performance of preOpt removeSimpleEquations (simulation): time 0.03978/0.6072, allocations: 33.85 MB / 0.6597 GB, free: 15.12 MB / 462.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.00772/0.615, allocations: 3.305 MB / 0.6629 GB, free: 11.71 MB / 462.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.001911/0.6169, allocations: 1.522 MB / 0.6644 GB, free: 10.18 MB / 462.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.01204/0.6289, allocations: 7.318 MB / 0.6716 GB, free: 2.719 MB / 462.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 3.481e-05/0.6289, allocations: 43.56 kB / 0.6716 GB, free: 2.668 MB / 462.1 MB
Notification: Performance of pre-optimization done (n=151): time 4.498e-06/0.629, allocations: 0 / 0.6716 GB, free: 2.668 MB / 462.1 MB
Notification: Performance of matching and sorting (n=188): time 0.06705/0.696, allocations: 19.21 MB / 0.6904 GB, free: 15.54 MB / 494.1 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.0001558/0.6962, allocations: 205.2 kB / 0.6906 GB, free: 15.29 MB / 494.1 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.007317/0.7035, allocations: 3.752 MB / 0.6942 GB, free: 11.58 MB / 494.1 MB
Notification: Performance of collectPreVariables (initialization): time 0.0003901/0.7039, allocations: 57.7 kB / 0.6943 GB, free: 11.52 MB / 494.1 MB
Notification: Performance of collectInitialEqns (initialization): time 0.003039/0.7069, allocations: 2.929 MB / 0.6971 GB, free: 8.59 MB / 494.1 MB
Notification: Performance of collectInitialBindings (initialization): time 0.001247/0.7082, allocations: 0.7481 MB / 0.6979 GB, free: 7.836 MB / 494.1 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.003027/0.7112, allocations: 1.175 MB / 0.699 GB, free: 6.648 MB / 494.1 MB
Notification: Performance of setup shared object (initialization): time 0.000152/0.7113, allocations: 301.1 kB / 0.6993 GB, free: 6.352 MB / 494.1 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.004113/0.7154, allocations: 2.108 MB / 0.7014 GB, free: 4.238 MB / 494.1 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.007734/0.7232, allocations: 5.648 MB / 0.7069 GB, free: 12.81 MB / 0.4981 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.01209/0.7353, allocations: 8.422 MB / 0.7151 GB, free: 2.637 MB / 0.4981 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 0.0001272/0.7354, allocations: 36 kB / 0.7151 GB, free: 2.602 MB / 0.4981 GB
Notification: Performance of matching and sorting (n=763) (initialization): time 0.02081/0.7562, allocations: 8.689 MB / 0.7236 GB, free: 9.902 MB / 0.5137 GB
Notification: Performance of prepare postOptimizeDAE: time 0.0001931/0.7564, allocations: 60 kB / 0.7237 GB, free: 9.844 MB / 0.5137 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0002639/0.7567, allocations: 125.4 kB / 0.7238 GB, free: 9.723 MB / 0.5137 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.005518/0.7622, allocations: 1.396 MB / 0.7252 GB, free: 8.324 MB / 0.5137 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.004574/0.7668, allocations: 1.302 MB / 0.7264 GB, free: 7.02 MB / 0.5137 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.01614/0.7829, allocations: 9.215 MB / 0.7354 GB, free: 13.67 MB / 0.5294 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.004284/0.7872, allocations: 299.6 kB / 0.7357 GB, free: 13.38 MB / 0.5294 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.001039/0.7882, allocations: 364 kB / 0.7361 GB, free: 13.02 MB / 0.5294 GB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 570
 * Number of states: 0 ()
 * Number of discrete variables: 36 (FixedTranslation2.color[3],FixedTranslation2.color[2],FixedTranslation2.color[1],force.massColor[3],force.massColor[2],force.massColor[1],force.color_b[3],force.color_b[2],force.color_b[1],force.color_a[3],force.color_a[2],force.color_a[1],FixedTranslation1.color[3],FixedTranslation1.color[2],FixedTranslation1.color[1],BodyBox1.color[3],BodyBox1.color[2],BodyBox1.color[1],BodyBox1.body.sphereColor[3],BodyBox1.body.sphereColor[2],BodyBox1.body.sphereColor[1],revolute.cylinderColor[3],revolute.cylinderColor[2],revolute.cylinderColor[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 (695):
 * Single equations (assignments): 691
 * Array equations: 3
 * 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
   {(1,44,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of prepare postOptimizeDAE: time 0.003997/0.7922, allocations: 1.889 MB / 0.7379 GB, free: 11.12 MB / 0.5294 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0009329/0.7932, allocations: 349.6 kB / 0.7383 GB, free: 10.78 MB / 0.5294 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.0101/0.8033, allocations: 3.755 MB / 0.7419 GB, free: 7 MB / 0.5294 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 4.995e-05/0.8033, allocations: 20 kB / 0.7419 GB, free: 6.98 MB / 0.5294 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 2.657e-05/0.8033, allocations: 8 kB / 0.7419 GB, free: 6.973 MB / 0.5294 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 4.148e-05/0.8034, allocations: 7.969 kB / 0.742 GB, free: 6.965 MB / 0.5294 GB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.02201/0.8254, allocations: 8.144 MB / 0.7499 GB, free: 14.76 MB / 0.545 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 3.064e-05/0.8254, allocations: 4 kB / 0.7499 GB, free: 14.75 MB / 0.545 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.001415/0.8268, allocations: 251.6 kB / 0.7502 GB, free: 14.51 MB / 0.545 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.00492/0.8317, allocations: 1.179 MB / 0.7513 GB, free: 13.32 MB / 0.545 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0003626/0.8321, allocations: 35.98 kB / 0.7513 GB, free: 13.29 MB / 0.545 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.0146/0.8467, allocations: 8.464 MB / 0.7596 GB, free: 4.684 MB / 0.545 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 5.61e-06/0.8467, allocations: 4.031 kB / 0.7596 GB, free: 4.68 MB / 0.545 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.01359/0.8603, allocations: 6.286 MB / 0.7657 GB, free: 14.36 MB / 0.5606 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.001239/0.8615, allocations: 394.6 kB / 0.7661 GB, free: 13.96 MB / 0.5606 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.0009986/0.8625, allocations: 28 kB / 0.7661 GB, free: 13.93 MB / 0.5606 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.001934/0.8645, allocations: 79.91 kB / 0.7662 GB, free: 13.85 MB / 0.5606 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.0006069/0.8651, allocations: 117 kB / 0.7663 GB, free: 13.74 MB / 0.5606 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0002752/0.8654, allocations: 59.97 kB / 0.7664 GB, free: 13.68 MB / 0.5606 GB
Notification: Performance of sorting global known variables: time 0.004785/0.8701, allocations: 2.332 MB / 0.7687 GB, free: 11.36 MB / 0.5606 GB
Notification: Performance of sort global known variables: time 2.5e-07/0.8701, allocations: 0 / 0.7687 GB, free: 11.36 MB / 0.5606 GB
Notification: Performance of remove unused functions: time 0.005195/0.8753, allocations: 0.9453 MB / 0.7696 GB, free: 10.42 MB / 0.5606 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 4
 * Number of states: 2 (revolute.phi,revolute.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 (130):
 * Single equations (assignments): 126
 * Array equations: 3
 * 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
   {(1,36,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of Backend phase and start with SimCode phase: time 0.01359/0.8889, allocations: 6.995 MB / 0.7764 GB, free: 3.383 MB / 0.5606 GB
Notification: Performance of simCode: created initialization part: time 0.01021/0.8991, allocations: 5.018 MB / 0.7813 GB, free: 14.38 MB / 0.5762 GB
Notification: Performance of simCode: created event and clocks part: time 7.063e-06/0.8991, allocations: 0 / 0.7813 GB, free: 14.38 MB / 0.5762 GB
Notification: Performance of simCode: created simulation system equations: time 0.003284/0.9024, allocations: 1.629 MB / 0.7829 GB, free: 12.74 MB / 0.5762 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.003545/0.906, allocations: 415.7 kB / 0.7833 GB, free: 12.34 MB / 0.5762 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.09092/0.9969, allocations: 44.27 MB / 0.8265 GB, free: 10.5 MB / 0.6231 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.005107/1.002, allocations: 2.965 MB / 0.8294 GB, free: 7.504 MB / 0.6231 GB
Notification: Performance of simCode: alias equations: time 0.004871/1.007, allocations: 1.807 MB / 0.8312 GB, free: 5.688 MB / 0.6231 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.002971/1.01, allocations: 1.647 MB / 0.8328 GB, free: 4.039 MB / 0.6231 GB
Notification: Performance of SimCode: time 1.383e-06/1.01, allocations: 0 / 0.8328 GB, free: 4.039 MB / 0.6231 GB
Notification: Performance of buildModelFMU: Generate the FMI files: time 0.3859/1.396, allocations: 67.3 MB / 0.8985 GB, free: 199.5 MB / 0.6387 GB
Notification: Performance of buildModelFMU: Generate platform static: time 27.83/29.23, allocations: 4.062 kB / 0.8985 GB, free: 199.5 MB / 0.6387 GB
"
[Timeout remaining time 631]
(rm -f ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.ForceWithTwoMasses.pipe ; mkfifo ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.ForceWithTwoMasses.pipe ; head -c 1048576 < ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.ForceWithTwoMasses.pipe >> ../files/ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.ForceWithTwoMasses.sim & /home/hudson/saved_omc/OMSimulator/install/bin/OMSimulator -r=ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.ForceWithTwoMasses_res.mat --tempDir=temp_ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_ForceWithTwoMasses_fmu --startTime=0 --stopTime=3 --stepSize=0.00059976 --timeout=50 --tolerance=1e-06 ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_ForceWithTwoMasses.fmu > ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.ForceWithTwoMasses.pipe 2>&1) [Timeout 52.5]
[Calling os._exit(0), Time elapsed: 32.170669368933886]
Failed to read output from testmodel.py, exit status != 0:
['time', 'revolute.phi', 'revolute.w']
29.356634898111224 29.36766249 29.174809584
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7fdc0bfde020>