Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.DifferentiationOfForces.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.001723/0.001723, allocations: 109.4 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.002075/0.002075, allocations: 217 kB / 23 MB, free: 5.582 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.487/1.487, allocations: 230.2 MB / 256.2 MB, free: 8.543 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.2254/0.2254, allocations: 46.89 MB / 359.4 MB, free: 4.898 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.DifferentiationOfForces,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_DifferentiationOfForces",fmuType="me",version="2.0",platforms={"static"})
"" <> buildModelFMU(ModelicaTest.MultiBody.Forces.DifferentiationOfForces,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_DifferentiationOfForces",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.0033/0.0033, allocations: 83.86 kB / 0.4941 GB, free: 8.988 MB / 366.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.3607/0.364, allocations: 65.98 MB / 0.5586 GB, free: 5.172 MB / 398.1 MB
Notification: Performance of NFInst.instantiate(ModelicaTest.MultiBody.Forces.DifferentiationOfForces): time 0.01147/0.3755, allocations: 9.575 MB / 0.5679 GB, free: 11.55 MB / 414.1 MB
Notification: Performance of NFInst.instExpressions: time 0.007591/0.383, allocations: 3.874 MB / 0.5717 GB, free: 7.664 MB / 414.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.001263/0.3843, allocations: 55.81 kB / 0.5718 GB, free: 7.609 MB / 414.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.005144/0.3895, allocations: 2.8 MB / 0.5745 GB, free: 4.801 MB / 414.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.00454/0.394, allocations: 1.646 MB / 0.5761 GB, free: 3.148 MB / 414.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.001635/0.3956, allocations: 0.7252 MB / 0.5768 GB, free: 2.422 MB / 414.1 MB
Notification: Performance of NFFlatten.flatten: time 0.00578/0.4014, allocations: 3.879 MB / 0.5806 GB, free: 14.54 MB / 430.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.003838/0.4052, allocations: 2.55 MB / 0.5831 GB, free: 11.92 MB / 430.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.002651/0.4079, allocations: 1.417 MB / 0.5845 GB, free: 10.5 MB / 430.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.003231/0.4111, allocations: 2.044 MB / 0.5865 GB, free: 8.445 MB / 430.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.000718/0.4118, allocations: 316 kB / 0.5868 GB, free: 8.137 MB / 430.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.002671/0.4145, allocations: 1.221 MB / 0.588 GB, free: 6.914 MB / 430.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.001927/0.4164, allocations: 1.788 MB / 0.5897 GB, free: 5.121 MB / 430.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.002473/0.4189, allocations: 2.09 MB / 0.5918 GB, free: 3.02 MB / 430.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.008622/0.4275, allocations: 6.857 MB / 0.5985 GB, free: 12.14 MB / 446.1 MB
Notification: Performance of FrontEnd - DAE generated: time 5.831e-06/0.4275, allocations: 4 kB / 0.5985 GB, free: 12.13 MB / 446.1 MB
Notification: Performance of FrontEnd: time 2.074e-06/0.4275, allocations: 0 / 0.5985 GB, free: 12.13 MB / 446.1 MB
Notification: Performance of Transformations before backend: time 0.0001838/0.4277, allocations: 0 / 0.5985 GB, free: 12.13 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: 1367
 * Number of variables: 1367
Notification: Performance of Generate backend data structure: time 0.01077/0.4385, allocations: 4.585 MB / 0.6029 GB, free: 7.477 MB / 446.1 MB
Notification: Performance of prepare preOptimizeDAE: time 4.989e-05/0.4386, allocations: 12.03 kB / 0.6029 GB, free: 7.465 MB / 446.1 MB
Notification: Performance of preOpt introduceOutputAliases (simulation): time 0.001033/0.4396, allocations: 0.6612 MB / 0.6036 GB, free: 6.793 MB / 446.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.08575/0.5253, allocations: 7.056 MB / 0.6105 GB, free: 15.73 MB / 462.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.006449/0.5318, allocations: 2.68 MB / 0.6131 GB, free: 12.98 MB / 462.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 0.0001819/0.532, allocations: 218 kB / 0.6133 GB, free: 12.77 MB / 462.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0007733/0.5327, allocations: 299.8 kB / 0.6136 GB, free: 12.47 MB / 462.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.01403/0.5468, allocations: 8.657 MB / 0.622 GB, free: 3.176 MB / 462.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 0.0001161/0.5469, allocations: 47.62 kB / 0.6221 GB, free: 3.129 MB / 462.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0003588/0.5472, allocations: 139.9 kB / 0.6222 GB, free: 2.992 MB / 462.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.0027/0.5499, allocations: 1.657 MB / 0.6238 GB, free: 1.332 MB / 462.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.01398/0.5639, allocations: 7.079 MB / 0.6308 GB, free: 10.25 MB / 478.1 MB
Notification: Performance of preOpt removeSimpleEquations (simulation): time 0.04353/0.6074, allocations: 33.28 MB / 0.6633 GB, free: 7.969 MB / 0.4981 GB
Notification: Performance of preOpt comSubExp (simulation): time 0.004907/0.6124, allocations: 2.291 MB / 0.6655 GB, free: 5.531 MB / 0.4981 GB
Notification: Performance of preOpt resolveLoops (simulation): time 0.00167/0.614, allocations: 1.114 MB / 0.6666 GB, free: 4.406 MB / 0.4981 GB
Notification: Performance of preOpt evalFunc (simulation): time 0.0003894/0.6144, allocations: 331.8 kB / 0.6669 GB, free: 4.027 MB / 0.4981 GB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 4.672e-05/0.6145, allocations: 55.05 kB / 0.6669 GB, free: 3.965 MB / 0.4981 GB
Notification: Performance of pre-optimization done (n=122): time 3.888e-06/0.6145, allocations: 0 / 0.6669 GB, free: 3.965 MB / 0.4981 GB
Notification: Performance of matching and sorting (n=140): time 0.02657/0.641, allocations: 10.69 MB / 0.6774 GB, free: 9.176 MB / 0.5137 GB
Notification: Performance of inlineWhenForInitialization (initialization): time 0.0001502/0.6412, allocations: 192.6 kB / 0.6776 GB, free: 8.945 MB / 0.5137 GB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.005383/0.6466, allocations: 3.588 MB / 0.6811 GB, free: 5.359 MB / 0.5137 GB
Notification: Performance of collectPreVariables (initialization): time 0.0002789/0.6468, allocations: 49.64 kB / 0.6811 GB, free: 5.305 MB / 0.5137 GB
Notification: Performance of collectInitialEqns (initialization): time 0.002504/0.6493, allocations: 2.956 MB / 0.684 GB, free: 2.32 MB / 0.5137 GB
Notification: Performance of collectInitialBindings (initialization): time 0.0009228/0.6503, allocations: 0.5817 MB / 0.6846 GB, free: 1.734 MB / 0.5137 GB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.00158/0.6518, allocations: 1.072 MB / 0.6856 GB, free: 0.6523 MB / 0.5137 GB
Notification: Performance of setup shared object (initialization): time 0.0001469/0.652, allocations: 309 kB / 0.6859 GB, free: 356 kB / 0.5137 GB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.002863/0.6549, allocations: 1.7 MB / 0.6876 GB, free: 14.64 MB / 0.5294 GB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.005386/0.6602, allocations: 5.068 MB / 0.6925 GB, free: 7.871 MB / 0.5294 GB
Notification: Performance of analyzeInitialSystem (initialization): time 0.009493/0.6697, allocations: 7.323 MB / 0.6997 GB, free: 14.86 MB / 0.545 GB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 9.882e-05/0.6698, allocations: 36 kB / 0.6997 GB, free: 14.83 MB / 0.545 GB
Notification: Performance of matching and sorting (n=682) (initialization): time 0.01341/0.6832, allocations: 6.751 MB / 0.7063 GB, free: 8.07 MB / 0.545 GB
Notification: Performance of prepare postOptimizeDAE: time 9.924e-05/0.6833, allocations: 56 kB / 0.7064 GB, free: 8.016 MB / 0.545 GB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 0.0001712/0.6835, allocations: 123.9 kB / 0.7065 GB, free: 7.895 MB / 0.545 GB
Notification: Performance of postOpt tearingSystem (initialization): time 0.001125/0.6846, allocations: 433.1 kB / 0.7069 GB, free: 7.469 MB / 0.545 GB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.004011/0.6886, allocations: 1.205 MB / 0.7081 GB, free: 6.262 MB / 0.545 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.004587/0.6932, allocations: 3.598 MB / 0.7116 GB, free: 2.527 MB / 0.545 GB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.004089/0.6973, allocations: 291.7 kB / 0.7119 GB, free: 2.242 MB / 0.545 GB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.001218/0.6985, allocations: 332 kB / 0.7122 GB, free: 1.918 MB / 0.545 GB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 544
 * Number of states: 0 ()
 * Number of discrete variables: 36 (forceAndTorque.torqueArrow.twoHeadedArrow,forceAndTorque.torqueArrow.headAtOrigin,forceAndTorque.forceArrow.twoHeadedArrow,forceAndTorque.forceArrow.headAtOrigin,cutForce.forceArrow.twoHeadedArrow,cutForce.forceArrow.headAtOrigin,forceAndTorque.torqueColor[3],forceAndTorque.torqueColor[2],forceAndTorque.torqueColor[1],forceAndTorque.forceColor[3],forceAndTorque.forceColor[2],forceAndTorque.forceColor[1],cutForce.forceColor[3],cutForce.forceColor[2],cutForce.forceColor[1],body.color[3],body.color[2],body.color[1],body.body.sphereColor[3],body.body.sphereColor[2],body.body.sphereColor[1],rev.cylinderColor[3],rev.cylinderColor[2],rev.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 (644):
 * Single equations (assignments): 640
 * 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,14,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of prepare postOptimizeDAE: time 0.00377/0.7023, allocations: 1.951 MB / 0.7141 GB, free: 15.96 MB / 0.5606 GB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0007222/0.703, allocations: 321.8 kB / 0.7144 GB, free: 15.64 MB / 0.5606 GB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.003912/0.7069, allocations: 1.87 MB / 0.7162 GB, free: 13.75 MB / 0.5606 GB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 3.65e-05/0.707, allocations: 16 kB / 0.7162 GB, free: 13.74 MB / 0.5606 GB
Notification: Performance of postOpt constantLinearSystem (simulation): time 8.606e-06/0.707, allocations: 7.938 kB / 0.7162 GB, free: 13.73 MB / 0.5606 GB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 1.788e-05/0.707, allocations: 7.984 kB / 0.7162 GB, free: 13.72 MB / 0.5606 GB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.0115/0.7185, allocations: 5.769 MB / 0.7219 GB, free: 7.887 MB / 0.5606 GB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 1.099e-05/0.7185, allocations: 0 / 0.7219 GB, free: 7.887 MB / 0.5606 GB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.001066/0.7196, allocations: 211.7 kB / 0.7221 GB, free: 7.68 MB / 0.5606 GB
Notification: Performance of postOpt tearingSystem (simulation): time 0.0007723/0.7204, allocations: 252.6 kB / 0.7223 GB, free: 7.43 MB / 0.5606 GB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 0.0001086/0.7205, allocations: 27.98 kB / 0.7223 GB, free: 7.402 MB / 0.5606 GB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.003825/0.7243, allocations: 3.173 MB / 0.7254 GB, free: 4.086 MB / 0.5606 GB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 4.388e-06/0.7243, allocations: 7.969 kB / 0.7255 GB, free: 4.078 MB / 0.5606 GB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.006437/0.7307, allocations: 3.952 MB / 0.7293 GB, free: 96 kB / 0.5606 GB
Notification: Performance of postOpt removeConstants (simulation): time 0.2675/0.9982, allocations: 362 kB / 0.7297 GB, free: 153.2 MB / 0.5606 GB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 0.0004551/0.9986, allocations: 20.31 kB / 0.7297 GB, free: 153.2 MB / 0.5606 GB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.001167/0.9998, allocations: 68.5 kB / 0.7297 GB, free: 153.2 MB / 0.5606 GB
Notification: Performance of postOpt findZeroCrossings (simulation): time 0.000289/1, allocations: 98.03 kB / 0.7298 GB, free: 153.2 MB / 0.5606 GB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 0.0001109/1, allocations: 41.34 kB / 0.7299 GB, free: 153.2 MB / 0.5606 GB
Notification: Performance of sorting global known variables: time 0.003761/1.004, allocations: 2.243 MB / 0.7321 GB, free: 153 MB / 0.5606 GB
Notification: Performance of sort global known variables: time 2.2e-07/1.004, allocations: 0 / 0.7321 GB, free: 153 MB / 0.5606 GB
Notification: Performance of remove unused functions: time 0.003613/1.008, allocations: 0.8186 MB / 0.7329 GB, free: 152.9 MB / 0.5606 GB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 4
 * Number of states: 2 (rev.phi,rev.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 (107):
 * Single equations (assignments): 103
 * 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,11,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of Backend phase and start with SimCode phase: time 0.00491/1.012, allocations: 4.591 MB / 0.7373 GB, free: 151 MB / 0.5606 GB
Notification: Performance of simCode: created initialization part: time 0.005253/1.018, allocations: 3.96 MB / 0.7412 GB, free: 149.8 MB / 0.5606 GB
Notification: Performance of simCode: created event and clocks part: time 5.55e-06/1.018, allocations: 0 / 0.7412 GB, free: 149.8 MB / 0.5606 GB
Notification: Performance of simCode: created simulation system equations: time 0.001362/1.019, allocations: 1.108 MB / 0.7423 GB, free: 149.4 MB / 0.5606 GB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.001984/1.021, allocations: 398.5 kB / 0.7427 GB, free: 149.2 MB / 0.5606 GB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.04012/1.061, allocations: 37.99 MB / 0.7798 GB, free: 110.5 MB / 0.5606 GB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.002847/1.064, allocations: 3.034 MB / 0.7827 GB, free: 107.4 MB / 0.5606 GB
Notification: Performance of simCode: alias equations: time 0.003332/1.067, allocations: 1.714 MB / 0.7844 GB, free: 105.7 MB / 0.5606 GB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.001812/1.069, allocations: 1.659 MB / 0.786 GB, free: 104 MB / 0.5606 GB
Notification: Performance of SimCode: time 1.202e-06/1.069, allocations: 0 / 0.786 GB, free: 104 MB / 0.5606 GB
Notification: Performance of buildModelFMU: Generate the FMI files: time 0.09237/1.162, allocations: 57.16 MB / 0.8419 GB, free: 47.16 MB / 0.5606 GB
Notification: Performance of buildModelFMU: Generate platform static: time 21.74/22.91, allocations: 11.84 kB / 0.8419 GB, free: 47.15 MB / 0.5606 GB
"
[Timeout remaining time 637]
(rm -f ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.DifferentiationOfForces.pipe ; mkfifo ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.DifferentiationOfForces.pipe ; head -c 1048576 < ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.DifferentiationOfForces.pipe >> ../files/ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.DifferentiationOfForces.sim & /home/hudson/saved_omc/OMSimulator/install/bin/OMSimulator -r=ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.DifferentiationOfForces_res.mat --tempDir=temp_ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_DifferentiationOfForces_fmu --startTime=0 --stopTime=1.1 --timeout=50 --tolerance=1e-06 ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Forces_DifferentiationOfForces.fmu > ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Forces.DifferentiationOfForces.pipe 2>&1) [Timeout 52.5]
[Calling os._exit(0), Time elapsed: 25.8606498070003]
Failed to read output from testmodel.py, exit status != 0:
['time', 'rev.phi', 'rev.w']
23.03122427899507 23.048090076 22.616877407
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7f29c0538a90>