Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.Planar.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.001797/0.001797, allocations: 121.2 kB / 18.5 MB, free: 4.578 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.001998/0.001998, allocations: 206.6 kB / 21.45 MB, free: 1.629 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.525/1.525, allocations: 230.4 MB / 254.7 MB, free: 14.86 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.2868/0.2868, allocations: 46.91 MB / 357.7 MB, free: 10.21 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.Joints.Planar,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Joints_Planar",fmuType="me",version="2.0",platforms={"static"})
"" <> buildModelFMU(ModelicaTest.MultiBody.Joints.Planar,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Joints_Planar",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.002341/0.002341, allocations: 79.86 kB / 0.4917 GB, free: 7.758 MB / 350.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.1431/0.1454, allocations: 66.04 MB / 0.5562 GB, free: 5.59 MB / 414.1 MB
Notification: Performance of NFInst.instantiate(ModelicaTest.MultiBody.Joints.Planar): time 0.0188/0.1642, allocations: 15.01 MB / 0.5708 GB, free: 6.504 MB / 430.1 MB
Notification: Performance of NFInst.instExpressions: time 0.012/0.1762, allocations: 4.454 MB / 0.5752 GB, free: 2.031 MB / 430.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.003937/0.1802, allocations: 91.62 kB / 0.5753 GB, free: 1.941 MB / 430.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.00568/0.1859, allocations: 2.25 MB / 0.5775 GB, free: 15.68 MB / 446.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.00661/0.1925, allocations: 2.035 MB / 0.5794 GB, free: 13.64 MB / 446.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.002013/0.1945, allocations: 0.6122 MB / 0.58 GB, free: 13.03 MB / 446.1 MB
Notification: Performance of NFFlatten.flatten: time 0.007318/0.2018, allocations: 4.303 MB / 0.5842 GB, free: 8.719 MB / 446.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.004341/0.2061, allocations: 2.721 MB / 0.5869 GB, free: 5.949 MB / 446.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.003243/0.2094, allocations: 1.62 MB / 0.5885 GB, free: 4.324 MB / 446.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.004121/0.2135, allocations: 2.422 MB / 0.5909 GB, free: 1.895 MB / 446.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.0009516/0.2145, allocations: 340 kB / 0.5912 GB, free: 1.562 MB / 446.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.002492/0.2169, allocations: 1.065 MB / 0.5922 GB, free: 0.4961 MB / 446.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.3373/0.5542, allocations: 2.003 MB / 0.5942 GB, free: 9.121 MB / 446.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.004135/0.5584, allocations: 2.381 MB / 0.5965 GB, free: 8.379 MB / 446.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.01278/0.5712, allocations: 7.779 MB / 0.6041 GB, free: 7.129 MB / 446.1 MB
Notification: Performance of FrontEnd - DAE generated: time 5.2e-06/0.5712, allocations: 0.7188 kB / 0.6041 GB, free: 7.129 MB / 446.1 MB
Notification: Performance of FrontEnd: time 1.443e-06/0.5712, allocations: 0 / 0.6041 GB, free: 7.129 MB / 446.1 MB
Notification: Performance of Transformations before backend: time 0.0002367/0.5714, allocations: 0.7188 kB / 0.6041 GB, free: 7.129 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: 1828
 * Number of variables: 1828
Notification: Performance of Generate backend data structure: time 0.01354/0.5849, allocations: 5.217 MB / 0.6092 GB, free: 4.938 MB / 446.1 MB
Notification: Performance of prepare preOptimizeDAE: time 4.908e-05/0.585, allocations: 10.16 kB / 0.6092 GB, free: 4.938 MB / 446.1 MB
Notification: Performance of preOpt introduceOutputAliases (simulation): time 0.002283/0.5873, allocations: 0.8557 MB / 0.61 GB, free: 4.855 MB / 446.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.01194/0.5992, allocations: 3.225 MB / 0.6132 GB, free: 4.508 MB / 446.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.007812/0.607, allocations: 2.607 MB / 0.6157 GB, free: 3.918 MB / 446.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0003473/0.6074, allocations: 251 kB / 0.616 GB, free: 3.91 MB / 446.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.002014/0.6094, allocations: 336 kB / 0.6163 GB, free: 3.902 MB / 446.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.02036/0.6298, allocations: 12.23 MB / 0.6282 GB, free: 14.73 MB / 462.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0001077/0.6299, allocations: 39.23 kB / 0.6283 GB, free: 14.73 MB / 462.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0005118/0.6304, allocations: 152.5 kB / 0.6284 GB, free: 14.66 MB / 462.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.00468/0.6351, allocations: 2.847 MB / 0.6312 GB, free: 13.57 MB / 462.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.02474/0.6598, allocations: 11.13 MB / 0.6421 GB, free: 5.359 MB / 462.1 MB
Notification: Performance of preOpt removeSimpleEquations (simulation): time 0.06932/0.7291, allocations: 40.59 MB / 0.6817 GB, free: 12.39 MB / 0.4981 GB
Notification: Performance of preOpt comSubExp (simulation): time 0.01158/0.7407, allocations: 4.51 MB / 0.6861 GB, free: 7.66 MB / 0.4981 GB
Notification: Performance of preOpt resolveLoops (simulation): time 0.003997/0.7447, allocations: 2.244 MB / 0.6883 GB, free: 5.418 MB / 0.4981 GB
Notification: Performance of preOpt evalFunc (simulation): time 0.001316/0.746, allocations: 1.322 MB / 0.6896 GB, free: 3.887 MB / 0.4981 GB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 5.686e-05/0.7461, allocations: 60.56 kB / 0.6897 GB, free: 3.816 MB / 0.4981 GB
Notification: Performance of pre-optimization done (n=249): time 4.729e-06/0.7461, allocations: 0 / 0.6897 GB, free: 3.816 MB / 0.4981 GB
Notification: Performance of matching and sorting (n=267): time 0.04674/0.7928, allocations: 18.75 MB / 0.708 GB, free: 0.9727 MB / 0.5137 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 7.469e-05/0.7929, allocations: 77.41 kB / 0.708 GB, free: 0.8828 MB / 0.5137 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.005399/0.7983, allocations: 3.185 MB / 0.7112 GB, free: 13.69 MB / 0.5294 GB
Notification: Performance of collectPreVariables (initialization): time 0.0004354/0.7987, allocations: 61.7 kB / 0.7112 GB, free: 13.62 MB / 0.5294 GB
Notification: Performance of collectInitialEqns (initialization): time 0.00277/0.8015, allocations: 3.238 MB / 0.7144 GB, free: 10.39 MB / 0.5294 GB
Notification: Performance of collectInitialBindings (initialization): time 0.001359/0.8028, allocations: 1.018 MB / 0.7154 GB, free: 9.391 MB / 0.5294 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.001926/0.8048, allocations: 1.19 MB / 0.7165 GB, free: 8.191 MB / 0.5294 GB
Notification: Performance of setup shared object (initialization): time 0.0001552/0.8049, allocations: 301.1 kB / 0.7168 GB, free: 7.895 MB / 0.5294 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.004061/0.809, allocations: 2.463 MB / 0.7192 GB, free: 5.43 MB / 0.5294 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.007099/0.8161, allocations: 5.72 MB / 0.7248 GB, free: 14.16 MB / 0.545 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.0135/0.8296, allocations: 8.974 MB / 0.7336 GB, free: 4.059 MB / 0.545 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 0.0001219/0.8297, allocations: 35 kB / 0.7336 GB, free: 4.027 MB / 0.545 GB
Notification: Performance of matching and sorting (n=787) (initialization): time 0.02333/0.853, allocations: 8.988 MB / 0.7424 GB, free: 11.45 MB / 0.5606 GB
Notification: Performance of prepare postOptimizeDAE: time 0.0001998/0.8532, allocations: 52 kB / 0.7424 GB, free: 11.4 MB / 0.5606 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0002486/0.8535, allocations: 112 kB / 0.7425 GB, free: 11.29 MB / 0.5606 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.005153/0.8586, allocations: 1.051 MB / 0.7436 GB, free: 10.24 MB / 0.5606 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.007064/0.8657, allocations: 1.345 MB / 0.7449 GB, free: 8.891 MB / 0.5606 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.01049/0.8762, allocations: 5.543 MB / 0.7503 GB, free: 3.215 MB / 0.5606 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.005581/0.8818, allocations: 315.9 kB / 0.7506 GB, free: 2.906 MB / 0.5606 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.001802/0.8836, allocations: 347.8 kB / 0.7509 GB, free: 2.566 MB / 0.5606 GB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 517
 * Number of states: 0 ()
 * Number of discrete variables: 46 (axis1.arrowLine.twoHeadedArrow,axis1.headAtOrigin,axis2.arrowLine.twoHeadedArrow,axis2.headAtOrigin,axis1.color[3],axis1.color[2],axis1.color[1],frame_a1.color_x[3],frame_a1.color_x[2],frame_a1.color_x[1],frame_a.color_x[3],frame_a.color_x[2],frame_a.color_x[1],body.sphereColor[3],body.sphereColor[2],body.sphereColor[1],planar.cylinderColor[3],planar.cylinderColor[2],planar.cylinderColor[1],planar.boxColor[3],planar.boxColor[2],planar.boxColor[1],planar.revolute.cylinderColor[3],planar.revolute.cylinderColor[2],planar.revolute.cylinderColor[1],planar.prismatic_y.boxColor[3],planar.prismatic_y.boxColor[2],planar.prismatic_y.boxColor[1],planar.prismatic_x.boxColor[3],planar.prismatic_x.boxColor[2],planar.prismatic_x.boxColor[1],axis2.color[3],axis2.color[2],axis2.color[1],world.groundColor[3],world.groundColor[2],world.groundColor[1],world.gravitySphereColor[3],world.gravitySphereColor[2],world.gravitySphereColor[1],world.gravityArrowColor[3],world.gravityArrowColor[2],world.gravityArrowColor[1],world.axisColor_x[3],world.axisColor_x[2],world.axisColor_x[1])
 * Number of discrete states: 0 ()
 * Number of clocked states: 0 ()
 * Top-level inputs: 0
Notification: Strong component statistics for initialization (725):
 * Single equations (assignments): 718
 * 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
   {(4,11,87.5%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of prepare postOptimizeDAE: time 0.00911/0.8927, allocations: 2.419 MB / 0.7533 GB, free: 140 kB / 0.5606 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.001691/0.8944, allocations: 329.9 kB / 0.7536 GB, free: 15.81 MB / 0.5762 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.01926/0.9136, allocations: 5.355 MB / 0.7588 GB, free: 10.4 MB / 0.5762 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 0.0001495/0.9138, allocations: 47.98 kB / 0.7589 GB, free: 10.35 MB / 0.5762 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 1.852e-05/0.9138, allocations: 4 kB / 0.7589 GB, free: 10.35 MB / 0.5762 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 6.244e-05/0.9139, allocations: 11.95 kB / 0.7589 GB, free: 10.34 MB / 0.5762 GB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.0447/0.9586, allocations: 13.02 MB / 0.7716 GB, free: 13.13 MB / 0.5919 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 4.445e-05/0.9586, allocations: 12 kB / 0.7716 GB, free: 13.12 MB / 0.5919 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.003706/0.9623, allocations: 424.2 kB / 0.772 GB, free: 12.71 MB / 0.5919 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.005665/0.968, allocations: 0.8874 MB / 0.7729 GB, free: 11.82 MB / 0.5919 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0007635/0.9687, allocations: 57.81 kB / 0.7729 GB, free: 11.76 MB / 0.5919 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.01234/0.9811, allocations: 4.83 MB / 0.7777 GB, free: 6.793 MB / 0.5919 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 3.043e-05/0.9811, allocations: 23.81 kB / 0.7777 GB, free: 6.77 MB / 0.5919 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.02287/1.004, allocations: 8.029 MB / 0.7855 GB, free: 14.52 MB / 0.6075 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.0016/1.006, allocations: 378.9 kB / 0.7859 GB, free: 14.13 MB / 0.6075 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.0009507/1.007, allocations: 55.98 kB / 0.7859 GB, free: 14.08 MB / 0.6075 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.002484/1.009, allocations: 150.5 kB / 0.7861 GB, free: 13.93 MB / 0.6075 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.0006501/1.01, allocations: 165.6 kB / 0.7862 GB, free: 13.77 MB / 0.6075 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0003044/1.01, allocations: 75.98 kB / 0.7863 GB, free: 13.7 MB / 0.6075 GB
Notification: Performance of sorting global known variables: time 0.005426/1.015, allocations: 1.957 MB / 0.7882 GB, free: 11.74 MB / 0.6075 GB
Notification: Performance of sort global known variables: time 1.71e-07/1.015, allocations: 0 / 0.7882 GB, free: 11.74 MB / 0.6075 GB
Notification: Performance of remove unused functions: time 0.009011/1.024, allocations: 1.065 MB / 0.7893 GB, free: 10.68 MB / 0.6075 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 49
 * Number of states: 6 (planar.s_x,planar.s_y,planar.phi,planar.v_x,planar.v_y,planar.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 (208):
 * Single equations (assignments): 201
 * 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
   {(3,9,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of Backend phase and start with SimCode phase: time 0.01604/1.04, allocations: 8.703 MB / 0.7978 GB, free: 1.758 MB / 0.6075 GB
Notification: Performance of simCode: created initialization part: time 0.01061/1.051, allocations: 5.761 MB / 0.8034 GB, free: 12.01 MB / 0.6231 GB
Notification: Performance of simCode: created event and clocks part: time 1.22e-05/1.051, allocations: 0 / 0.8034 GB, free: 12.01 MB / 0.6231 GB
Notification: Performance of simCode: created simulation system equations: time 0.003717/1.055, allocations: 2.109 MB / 0.8054 GB, free: 9.891 MB / 0.6231 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.002817/1.058, allocations: 456.8 kB / 0.8059 GB, free: 9.453 MB / 0.6231 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.3384/1.396, allocations: 47 MB / 0.8518 GB, free: 237.3 MB / 0.6544 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.004054/1.4, allocations: 3.715 MB / 0.8554 GB, free: 236.5 MB / 0.6544 GB
Notification: Performance of simCode: alias equations: time 0.003955/1.404, allocations: 2.149 MB / 0.8575 GB, free: 236.4 MB / 0.6544 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.002656/1.407, allocations: 2.101 MB / 0.8596 GB, free: 235.2 MB / 0.6544 GB
Notification: Performance of SimCode: time 1.423e-06/1.407, allocations: 0.8438 kB / 0.8596 GB, free: 235.2 MB / 0.6544 GB
Notification: Performance of buildModelFMU: Generate the FMI files: time 0.1019/1.509, allocations: 67.12 MB / 0.9251 GB, free: 179.4 MB / 0.6544 GB
Notification: Performance of buildModelFMU: Generate platform static: time 26.73/28.24, allocations: 14.45 kB / 0.9251 GB, free: 179.4 MB / 0.6544 GB
"
[Timeout remaining time 632]
(rm -f ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.Planar.pipe ; mkfifo ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.Planar.pipe ; head -c 1048576 < ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.Planar.pipe >> ../files/ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.Planar.sim & python3 -m fmpy simulate  --output-file ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.Planar_res.csv --start-time 0 --stop-time 1.1 --timeout 50 --relative-tolerance 1e-06 --interface-type ModelExchange --solver CVode --output-interval 0.000219912 ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Joints_Planar.fmu > ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.Planar.pipe 2>&1) [Timeout 52.5]
[Calling os._exit(0), Time elapsed: 31.58692743210122]
Failed to read output from testmodel.py, exit status != 0:
['time', 'planar.phi', 'planar.s_x', 'planar.s_y', 'planar.v_x', 'planar.v_y', 'planar.w']
28.36089724022895 28.378726107 27.803754518
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7f21705297e0>