getComponentAnnotations is too slow on MSL components

[Francesco Casella]

This is the performance log reported by OMEdit when opening the MultiBody library subtree in the package browser.

Commands	Time (secs)
getComponentAnnotations(Modelica.Mechanics.MultiBody.World)	9.787
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.FreeMotionScalarInit)	18.465
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Planar)	9.146
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.UniversalSpherical)	9.435
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.SphericalSpherical)	5.665
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Universal)	4.947

As a consequence, the MultiBody library is practically unusable in OMEdit, unless one has really a lot of patience and faith in the eventual success of the operation. See #2960 for further details.

There is no obvious reason why getting the annotations of a single component should take all of this time. Please do profile this function and make it reasonably efficient.

[Per Östlund]

This should be improved as soon as Hudson feels like looking at my pull request (edit: now merged as 68966eb). Calling getComponentAnnotations with my improvements now takes about 3 seconds for all the listed Models together. Still a bit slow, but I guess we can take the priority down a few notches at least.

[Adeel Asghar]

New results after Per's improvements,

Commands	Time (secs)
getComponentAnnotations(Modelica.Mechanics.MultiBody.World)	0.539
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.FreeMotionScalarInit)	0.619
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Planar)	1.282
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.UniversalSpherical)	0.577
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.SphericalSpherical)	0.616
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Universal)	1.03

[Martin Sjölund]

Milestone pushed to 1.9.5

[Martin Sjölund]

Milestone renamed

[Francesco Casella]

Replying to adeas31:

New results after Per's improvements,

Apparently Adeel's using a fast computer. On my laptop, which is an energy-saving i5-4200U running between 1.6 and 2.3 GHz, the times are 80% larger than reported by Adeel, which brings the time to open the Joints subtree at about 22 seconds.

@perost, IMHO this is really not acceptable, at least not for the 2.0.0 release that should mark the transition of OMC to "serious general-purpose use, no restrictions". Life's too short to wait almost half a minute for a MSL subtree to open, not to mention the several seconds taken when I drag and drop each new component from that tree. So, I'm bringing this back to blocker, for the 2.0.0 release.

I think we should reduce the time taken by each getComponentAnnotations call to not more than 100-200 ms, possibly by introducing partial instantiation, i.e. only instantiate annotations and forget about everything else. For instance, on the log file at some point I read:

getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Revolute) 23:12:41:783
{{Placement(true,-,-,10.0,90.0,-10.0,110.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,-70.0,90.0,-50.0,110.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,-116.0,-16.0,-84.0,16.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,84.0,-16.0,116.0,16.0,-,-,-,-,-,-,-,)},{Evaluate=true, HideResult=true, choices(error)},{},{Evaluate=true},{},{Dialog("Animation","if animation = true",true,-,false,"","","","","",false)},{Dialog("Animation","if animation = true",true,-,false,"","","","","",false)},{Dialog("Animation","if animation = true",true,-,true,"","","","","",false)},{Dialog("Animation","if animation = true",true,-,false,"","","","","",false)},{Dialog("Advanced","",true,-,false,"","","","","",false)},{unassignedMessage="
The rotation angle phi of a revolute joint cannot be determined.
Possible reasons:
- A non-zero mass might be missing on either side of the parts
  connected to the revolute joint.
- Too many StateSelect.always are defined and the model
  has less degrees of freedom as specified with this setting
  (remove all StateSelect.always settings).
"},{},{},{},{},{},{},{},{},{Placement(true,-,-,-70.0,70.0,-50.0,90.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,-10.0,90.0,10.0,70.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,40.0,70.0,20.0,90.0,-,-,-,-,-,-,-,)}} 23:12:42:755
0.972 secs (14.695 secs)

Now, why on earth should this kind of analysis be carried out to display a package tree in the class browser? It seems to me that these functions are wasting the majority of time doing totally irrelevant stuff. I really cannot believe that it should take such a long time to just collect a bunch of graphical annotations.

[Adeel Asghar]

Replying to casella:

Replying to adeas31:

New results after Per's improvements,

Apparently Adeel's using a fast computer. On my laptop, which is an energy-saving i5-4200U running between 1.6 and 2.3 GHz, the times are 80% larger than reported by Adeel, which brings the time to open the Joints subtree at about 22 seconds.

@perost, IMHO this is really not acceptable, at least not for the 2.0.0 release that should mark the transition of OMC to "serious general-purpose use, no restrictions". Life's too short to wait almost half a minute for a MSL subtree to open, not to mention the several seconds taken when I drag and drop each new component from that tree. So, I'm bringing this back to blocker, for the 2.0.0 release.

I think we should reduce the time taken by each getComponentAnnotations call to not more than 100-200 ms, possibly by introducing partial instantiation, i.e. only instantiate annotations and forget about everything else. For instance, on the log file at some point I read:

getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Revolute) 23:12:41:783
{{Placement(true,-,-,10.0,90.0,-10.0,110.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,-70.0,90.0,-50.0,110.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,-116.0,-16.0,-84.0,16.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,84.0,-16.0,116.0,16.0,-,-,-,-,-,-,-,)},{Evaluate=true, HideResult=true, choices(error)},{},{Evaluate=true},{},{Dialog("Animation","if animation = true",true,-,false,"","","","","",false)},{Dialog("Animation","if animation = true",true,-,false,"","","","","",false)},{Dialog("Animation","if animation = true",true,-,true,"","","","","",false)},{Dialog("Animation","if animation = true",true,-,false,"","","","","",false)},{Dialog("Advanced","",true,-,false,"","","","","",false)},{unassignedMessage="
The rotation angle phi of a revolute joint cannot be determined.
Possible reasons:
- A non-zero mass might be missing on either side of the parts
  connected to the revolute joint.
- Too many StateSelect.always are defined and the model
  has less degrees of freedom as specified with this setting
  (remove all StateSelect.always settings).
"},{},{},{},{},{},{},{},{},{Placement(true,-,-,-70.0,70.0,-50.0,90.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,-10.0,90.0,10.0,70.0,-,-,-,-,-,-,-,)},{Placement(true,-,-,40.0,70.0,20.0,90.0,-,-,-,-,-,-,-,)}} 23:12:42:755
0.972 secs (14.695 secs)

Now, why on earth should this kind of analysis be carried out to display a package tree in the class browser? It seems to me that these functions are wasting the majority of time doing totally irrelevant stuff. I really cannot believe that it should take such a long time to just collect a bunch of graphical annotations.

What do you mean? Which analysis?

[Adrian Pop]

Yes, we do a lot of stuff to get the annotations, basically a partial instantiation if the annotation contains parameters from the model.

[Francesco Casella]

Replying to adeas31:

What do you mean? Which analysis?

Sorry, I saw the diagnostic message and I missed the unassignedMessage=" at the end of the previous line, so I was mislead in thinking that some structural analysis was performed :)

[Francesco Casella]

This issue should already be fixed with 1.13.0

[Francesco Casella]

Rescheduled to 1.14.0

[Adrian Pop]

When using NF for getComponentAnnotations running script:

loadModel(Modelica); getErrorString();

getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.FreeMotionScalarInit); getErrorString();
getComponentAnnotations(Modelica.Mechanics.MultiBody.World); getErrorString();
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Planar); getErrorString();
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.UniversalSpherical); getErrorString();
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.SphericalSpherical); getErrorString();
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Universal); getErrorString();
getComponentAnnotations(Modelica.Mechanics.MultiBody.Joints.Revolute); getErrorString();

adrpo33@ida-0030 MINGW64 /c/home/adrpo33/dev/OMTesting/bugs/3679
$ time ~/dev/OpenModelica/build/bin/omc -d=nfAPI,newInst t.mos
real    0m3.678s
user    0m0.000s
sys     0m0.031s

adrpo33@ida-0030 MINGW64 /c/home/adrpo33/dev/OMTesting/bugs/3679
$ time ~/dev/OpenModelica/build/bin/omc t.mos
real    1m11.504s
user    0m0.015s
sys     0m0.015s

[Francesco Casella]

As advertised at the Annual Workshop, 20X speed increase :)

This is really very good news!