Running: ./testmodel.py --libraries=/home/hudson/saved_omc/libraries/.openmodelica/libraries --ompython_omhome=/usr ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.PrismaticInit.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.001355/0.001355, allocations: 112.3 kB / 20.22 MB, free: 1.793 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.001862/0.001862, allocations: 215.5 kB / 23.48 MB, free: 5.227 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.539/1.539, allocations: 230.2 MB / 256.8 MB, free: 8.562 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.2437/0.2437, allocations: 46.88 MB / 360 MB, free: 4.699 MB / 286.1 MB
"
[Timeout remaining time 179]
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.PrismaticInit,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Joints_PrismaticInit",fmuType="me",version="2.0",platforms={"static"})
"" <> buildModelFMU(ModelicaTest.MultiBody.Joints.PrismaticInit,fileNamePrefix="ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Joints_PrismaticInit",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.002288/0.002288, allocations: 75.88 kB / 0.4951 GB, free: 8.504 MB / 366.1 MB
Notification: Performance of FrontEnd - Absyn->SCode: time 0.3617/0.364, allocations: 66 MB / 0.5595 GB, free: 4.945 MB / 398.1 MB
Notification: Performance of NFInst.instantiate(ModelicaTest.MultiBody.Joints.PrismaticInit): time 0.01043/0.3745, allocations: 8.698 MB / 0.568 GB, free: 12.2 MB / 414.1 MB
Notification: Performance of NFInst.instExpressions: time 0.006951/0.3814, allocations: 3.512 MB / 0.5715 GB, free: 8.676 MB / 414.1 MB
Notification: Performance of NFInst.updateImplicitVariability: time 0.001391/0.3828, allocations: 47.88 kB / 0.5715 GB, free: 8.629 MB / 414.1 MB
Notification: Performance of NFTyping.typeComponents: time 0.002987/0.3858, allocations: 1.382 MB / 0.5729 GB, free: 7.242 MB / 414.1 MB
Notification: Performance of NFTyping.typeBindings: time 0.002605/0.3884, allocations: 0.93 MB / 0.5738 GB, free: 6.309 MB / 414.1 MB
Notification: Performance of NFTyping.typeClassSections: time 0.001203/0.3896, allocations: 0.5225 MB / 0.5743 GB, free: 5.785 MB / 414.1 MB
Notification: Performance of NFFlatten.flatten: time 0.002664/0.3923, allocations: 1.718 MB / 0.576 GB, free: 4.062 MB / 414.1 MB
Notification: Performance of NFFlatten.resolveConnections: time 0.001527/0.3938, allocations: 1.163 MB / 0.5771 GB, free: 2.859 MB / 414.1 MB
Notification: Performance of NFEvalConstants.evaluate: time 0.001061/0.3948, allocations: 0.662 MB / 0.5777 GB, free: 2.195 MB / 414.1 MB
Notification: Performance of NFSimplifyModel.simplify: time 0.001449/0.3963, allocations: 0.9464 MB / 0.5787 GB, free: 1.246 MB / 414.1 MB
Notification: Performance of NFPackage.collectConstants: time 0.0002713/0.3966, allocations: 136 kB / 0.5788 GB, free: 1.113 MB / 414.1 MB
Notification: Performance of NFFlatten.collectFunctions: time 0.001171/0.3977, allocations: 0.5929 MB / 0.5794 GB, free: 0.5195 MB / 414.1 MB
Notification: Performance of NFScalarize.scalarize: time 0.000768/0.3985, allocations: 0.7402 MB / 0.5801 GB, free: 15.78 MB / 430.1 MB
Notification: Performance of NFVerifyModel.verify: time 0.0009335/0.3994, allocations: 0.8314 MB / 0.5809 GB, free: 14.94 MB / 430.1 MB
Notification: Performance of NFConvertDAE.convert: time 0.002905/0.4023, allocations: 2.483 MB / 0.5833 GB, free: 12.45 MB / 430.1 MB
Notification: Performance of FrontEnd - DAE generated: time 5.69e-06/0.4023, allocations: 4 kB / 0.5833 GB, free: 12.45 MB / 430.1 MB
Notification: Performance of FrontEnd: time 1.553e-06/0.4023, allocations: 0 / 0.5833 GB, free: 12.45 MB / 430.1 MB
Notification: Performance of Transformations before backend: time 4.016e-05/0.4024, allocations: 0 / 0.5833 GB, free: 12.45 MB / 430.1 MB
Notification: Model statistics after passing the front-end and creating the data structures used by the back-end:
 * Number of equations: 449
 * Number of variables: 449
Notification: Performance of Generate backend data structure: time 0.00366/0.406, allocations: 2.054 MB / 0.5853 GB, free: 10.33 MB / 430.1 MB
Notification: Performance of prepare preOptimizeDAE: time 4.576e-05/0.4061, allocations: 15.97 kB / 0.5854 GB, free: 10.32 MB / 430.1 MB
Notification: Performance of preOpt introduceOutputAliases (simulation): time 0.0003001/0.4064, allocations: 249.5 kB / 0.5856 GB, free: 10.06 MB / 430.1 MB
Notification: Performance of preOpt normalInlineFunction (simulation): time 0.001127/0.4075, allocations: 287.5 kB / 0.5859 GB, free: 9.781 MB / 430.1 MB
Notification: Performance of preOpt evaluateParameters (simulation): time 0.002313/0.4098, allocations: 1.29 MB / 0.5871 GB, free: 8.445 MB / 430.1 MB
Notification: Performance of preOpt simplifyIfEquations (simulation): time 8.262e-05/0.4099, allocations: 94.41 kB / 0.5872 GB, free: 8.352 MB / 430.1 MB
Notification: Performance of preOpt expandDerOperator (simulation): time 0.0001905/0.4101, allocations: 124 kB / 0.5873 GB, free: 8.23 MB / 430.1 MB
Notification: Performance of preOpt clockPartitioning (simulation): time 0.005678/0.4158, allocations: 2.996 MB / 0.5903 GB, free: 5.035 MB / 430.1 MB
Notification: Performance of preOpt findStateOrder (simulation): time 5.288e-05/0.4158, allocations: 23.88 kB / 0.5903 GB, free: 5.012 MB / 430.1 MB
Notification: Performance of preOpt replaceEdgeChange (simulation): time 0.0001251/0.416, allocations: 59.91 kB / 0.5903 GB, free: 4.953 MB / 430.1 MB
Notification: Performance of preOpt inlineArrayEqn (simulation): time 0.0006171/0.4166, allocations: 434 kB / 0.5908 GB, free: 4.527 MB / 430.1 MB
Notification: Performance of preOpt removeEqualRHS (simulation): time 0.004892/0.4215, allocations: 2.171 MB / 0.5929 GB, free: 2.348 MB / 430.1 MB
Notification: Performance of preOpt removeSimpleEquations (simulation): time 0.01376/0.4352, allocations: 10.71 MB / 0.6033 GB, free: 7.363 MB / 446.1 MB
Notification: Performance of preOpt comSubExp (simulation): time 0.004047/0.4393, allocations: 1.195 MB / 0.6045 GB, free: 6.152 MB / 446.1 MB
Notification: Performance of preOpt resolveLoops (simulation): time 0.0006211/0.4399, allocations: 379.2 kB / 0.6049 GB, free: 5.777 MB / 446.1 MB
Notification: Performance of preOpt evalFunc (simulation): time 0.004195/0.4441, allocations: 3.081 MB / 0.6079 GB, free: 2.43 MB / 446.1 MB
Notification: Performance of preOpt encapsulateWhenConditions (simulation): time 3.856e-05/0.4441, allocations: 39 kB / 0.6079 GB, free: 2.383 MB / 446.1 MB
Notification: Performance of pre-optimization done (n=51): time 4.137e-06/0.4441, allocations: 3.984 kB / 0.6079 GB, free: 2.379 MB / 446.1 MB
Notification: Performance of matching and sorting (n=57): time 0.01219/0.4563, allocations: 3.81 MB / 0.6116 GB, free: 14.45 MB / 462.1 MB
Notification: Performance of inlineWhenForInitialization (initialization): time 7.539e-05/0.4564, allocations: 85.67 kB / 0.6117 GB, free: 14.35 MB / 462.1 MB
Notification: Performance of selectInitializationVariablesDAE (initialization): time 0.001626/0.458, allocations: 1.198 MB / 0.6129 GB, free: 13.14 MB / 462.1 MB
Notification: Performance of collectPreVariables (initialization): time 4.832e-05/0.4581, allocations: 37.7 kB / 0.6129 GB, free: 13.1 MB / 462.1 MB
Notification: Performance of collectInitialEqns (initialization): time 0.0007406/0.4588, allocations: 0.9663 MB / 0.6139 GB, free: 12.12 MB / 462.1 MB
Notification: Performance of collectInitialBindings (initialization): time 0.0001949/0.459, allocations: 222.2 kB / 0.6141 GB, free: 11.9 MB / 462.1 MB
Notification: Performance of simplifyInitialFunctions (initialization): time 0.0003942/0.4594, allocations: 315.4 kB / 0.6144 GB, free: 11.59 MB / 462.1 MB
Notification: Performance of setup shared object (initialization): time 0.0001251/0.4595, allocations: 301.1 kB / 0.6147 GB, free: 11.29 MB / 462.1 MB
Notification: Performance of preBalanceInitialSystem (initialization): time 0.0006648/0.4602, allocations: 411.7 kB / 0.6151 GB, free: 10.89 MB / 462.1 MB
Notification: Performance of partitionIndependentBlocks (initialization): time 0.001327/0.4615, allocations: 1.254 MB / 0.6163 GB, free: 9.219 MB / 462.1 MB
Notification: Performance of analyzeInitialSystem (initialization): time 0.002239/0.4638, allocations: 1.806 MB / 0.618 GB, free: 7 MB / 462.1 MB
Notification: Performance of solveInitialSystemEqSystem (initialization): time 1.252e-05/0.4638, allocations: 8 kB / 0.6181 GB, free: 6.992 MB / 462.1 MB
Notification: Performance of matching and sorting (n=194) (initialization): time 0.002821/0.4666, allocations: 1.719 MB / 0.6197 GB, free: 5.262 MB / 462.1 MB
Notification: Performance of prepare postOptimizeDAE: time 3.296e-05/0.4666, allocations: 16 kB / 0.6197 GB, free: 5.246 MB / 462.1 MB
Notification: Performance of postOpt simplifyComplexFunction (initialization): time 3.1e-05/0.4667, allocations: 28 kB / 0.6198 GB, free: 5.219 MB / 462.1 MB
Notification: Performance of postOpt tearingSystem (initialization): time 0.0002195/0.4669, allocations: 96.75 kB / 0.6199 GB, free: 5.121 MB / 462.1 MB
Notification: Performance of postOpt solveSimpleEquations (initialization): time 0.001054/0.4679, allocations: 347.4 kB / 0.6202 GB, free: 4.781 MB / 462.1 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (initialization): time 0.001786/0.4697, allocations: 1.885 MB / 0.622 GB, free: 2.75 MB / 462.1 MB
Notification: Performance of postOpt simplifyAllExpressions (initialization): time 0.0009316/0.4706, allocations: 76.05 kB / 0.6221 GB, free: 2.676 MB / 462.1 MB
Notification: Performance of postOpt collapseArrayExpressions (initialization): time 0.0001025/0.4707, allocations: 84 kB / 0.6222 GB, free: 2.594 MB / 462.1 MB
Notification: Model statistics after passing the back-end for initialization:
 * Number of independent subsystems: 134
 * Number of states: 0 ()
 * Number of discrete variables: 27 (fixedTranslation.color[3],fixedTranslation.color[2],fixedTranslation.color[1],spring.color[3],spring.color[2],spring.color[1],spring.massColor[3],spring.massColor[2],spring.massColor[1],body.sphereColor[3],body.sphereColor[2],body.sphereColor[1],prismatic.boxColor[3],prismatic.boxColor[2],prismatic.boxColor[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 (190):
 * Single equations (assignments): 189
 * Array equations: 0
 * 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,4,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of prepare postOptimizeDAE: time 0.0009771/0.4717, allocations: 0.6401 MB / 0.6228 GB, free: 1.945 MB / 462.1 MB
Notification: Performance of postOpt lateInlineFunction (simulation): time 0.0001986/0.4719, allocations: 119.2 kB / 0.6229 GB, free: 1.828 MB / 462.1 MB
Notification: Performance of postOpt wrapFunctionCalls (simulation): time 0.0002717/0.4722, allocations: 139.6 kB / 0.6231 GB, free: 1.691 MB / 462.1 MB
Notification: Performance of postOpt inlineArrayEqn (simulation): time 8.295e-06/0.4722, allocations: 8 kB / 0.6231 GB, free: 1.684 MB / 462.1 MB
Notification: Performance of postOpt constantLinearSystem (simulation): time 9.157e-06/0.4722, allocations: 4 kB / 0.6231 GB, free: 1.68 MB / 462.1 MB
Notification: Performance of postOpt simplifysemiLinear (simulation): time 8.095e-06/0.4722, allocations: 3.984 kB / 0.6231 GB, free: 1.676 MB / 462.1 MB
Notification: Performance of postOpt removeSimpleEquations (simulation): time 0.003607/0.4758, allocations: 2.239 MB / 0.6253 GB, free: 15.33 MB / 478.1 MB
Notification: Performance of postOpt simplifyComplexFunction (simulation): time 8.205e-06/0.4758, allocations: 4 kB / 0.6253 GB, free: 15.32 MB / 478.1 MB
Notification: Performance of postOpt solveSimpleEquations (simulation): time 0.0003968/0.4762, allocations: 95.83 kB / 0.6254 GB, free: 15.23 MB / 478.1 MB
Notification: Performance of postOpt tearingSystem (simulation): time 0.0001981/0.4764, allocations: 64.81 kB / 0.6254 GB, free: 15.16 MB / 478.1 MB
Notification: Performance of postOpt inputDerivativesUsed (simulation): time 3.347e-05/0.4765, allocations: 15.94 kB / 0.6254 GB, free: 15.15 MB / 478.1 MB
Notification: Performance of postOpt calculateStrongComponentJacobians (simulation): time 0.001826/0.4783, allocations: 1.945 MB / 0.6273 GB, free: 13.07 MB / 478.1 MB
Notification: Performance of postOpt calculateStateSetsJacobians (simulation): time 4.999e-06/0.4783, allocations: 4 kB / 0.6273 GB, free: 13.06 MB / 478.1 MB
Notification: Performance of postOpt symbolicJacobian (simulation): time 0.001665/0.48, allocations: 1.114 MB / 0.6284 GB, free: 11.88 MB / 478.1 MB
Notification: Performance of postOpt removeConstants (simulation): time 0.000272/0.4802, allocations: 184.3 kB / 0.6286 GB, free: 11.68 MB / 478.1 MB
Notification: Performance of postOpt simplifyTimeIndepFuncCalls (simulation): time 9.761e-05/0.4803, allocations: 16 kB / 0.6286 GB, free: 11.67 MB / 478.1 MB
Notification: Performance of postOpt simplifyAllExpressions (simulation): time 0.0003662/0.4807, allocations: 31.91 kB / 0.6286 GB, free: 11.64 MB / 478.1 MB
Notification: Performance of postOpt findZeroCrossings (simulation): time 7.627e-05/0.4808, allocations: 51.94 kB / 0.6287 GB, free: 11.59 MB / 478.1 MB
Notification: Performance of postOpt collapseArrayExpressions (simulation): time 3.292e-05/0.4808, allocations: 20.06 kB / 0.6287 GB, free: 11.57 MB / 478.1 MB
Notification: Performance of sorting global known variables: time 0.001045/0.4818, allocations: 0.7635 MB / 0.6295 GB, free: 10.8 MB / 478.1 MB
Notification: Performance of sort global known variables: time 1.11e-07/0.4818, allocations: 0 / 0.6295 GB, free: 10.8 MB / 478.1 MB
Notification: Performance of remove unused functions: time 0.001362/0.4832, allocations: 299.9 kB / 0.6297 GB, free: 10.5 MB / 478.1 MB
Notification: Model statistics after passing the back-end for simulation:
 * Number of independent subsystems: 17
 * Number of states: 2 (prismatic.s,prismatic.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 (53):
 * Single equations (assignments): 52
 * Array equations: 0
 * 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,6,100.0%)}
 * Non-linear torn systems (#iteration vars, #inner vars): 0 systems
Notification: Performance of Backend phase and start with SimCode phase: time 0.001982/0.4852, allocations: 1.683 MB / 0.6314 GB, free: 8.742 MB / 478.1 MB
Notification: Performance of simCode: created initialization part: time 0.001925/0.4871, allocations: 1.069 MB / 0.6324 GB, free: 7.672 MB / 478.1 MB
Notification: Performance of simCode: created event and clocks part: time 4.488e-06/0.4871, allocations: 0 / 0.6324 GB, free: 7.672 MB / 478.1 MB
Notification: Performance of simCode: created simulation system equations: time 0.0006065/0.4877, allocations: 404 kB / 0.6328 GB, free: 7.266 MB / 478.1 MB
Notification: Performance of simCode: created of all other equations (e.g. parameter, nominal, assert, etc): time 0.001/0.4887, allocations: 176.7 kB / 0.633 GB, free: 7.09 MB / 478.1 MB
Notification: Performance of simCode: created linear, non-linear and system jacobian parts: time 0.01792/0.5066, allocations: 11.52 MB / 0.6442 GB, free: 10.51 MB / 494.1 MB
Notification: Performance of simCode: some other stuff during SimCode phase: time 0.001755/0.5084, allocations: 1.454 MB / 0.6457 GB, free: 9.023 MB / 494.1 MB
Notification: Performance of simCode: alias equations: time 0.00128/0.5097, allocations: 409.6 kB / 0.646 GB, free: 8.621 MB / 494.1 MB
Notification: Performance of simCode: all other stuff during SimCode phase: time 0.0009046/0.5106, allocations: 0.5774 MB / 0.6466 GB, free: 8.043 MB / 494.1 MB
Notification: Performance of SimCode: time 2.215e-06/0.5106, allocations: 0 / 0.6466 GB, free: 8.043 MB / 494.1 MB
Notification: Performance of buildModelFMU: Generate the FMI files: time 0.06316/0.5738, allocations: 23.2 MB / 0.6693 GB, free: 1.02 MB / 0.4981 GB
Notification: Performance of buildModelFMU: Generate platform static: time 12.35/12.93, allocations: 11.48 kB / 0.6693 GB, free: 1.012 MB / 0.4981 GB
"
[Timeout remaining time 647]
(rm -f ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.PrismaticInit.pipe ; mkfifo ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.PrismaticInit.pipe ; head -c 1048576 < ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.PrismaticInit.pipe >> ../files/ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.PrismaticInit.sim & python3 -m fmpy simulate  --output-file ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.PrismaticInit_res.csv --start-time 0 --stop-time 5 --timeout 50 --relative-tolerance 1e-06 --interface-type ModelExchange --solver CVode --output-interval 0.0009996 ModelicaTest_4_1_0-beta_om_ModelicaTest_MultiBody_Joints_PrismaticInit.fmu > ModelicaTest_4.1.0-beta.om_ModelicaTest.MultiBody.Joints.PrismaticInit.pipe 2>&1) [Timeout 52.5]
[Calling os._exit(0), Time elapsed: 16.03410853794776]
Failed to read output from testmodel.py, exit status != 0:
['time', 'prismatic.s', 'prismatic.v']
13.022903421893716 13.047165852 12.640294623
Calling exit ...
<OMPython.OMCSessionZMQ object at 0x7fbbdf38e020>