Further speed up of NF API

[casella]

Collect here the discussion on making the OMEdit faster when displaying models.

[adrpo]

The only API that currently uses the NF is getComponentAnnotations, I haven't pushed in the code for the other ones yet as it has some issues. I'm working on this now.

[casella]

OK, good!

I changed the title of the ticket, feel free to close it when you push your code in.

[adrpo]

Fixed in 0e102b/OpenModelica.

	old API	new API
getIconAnnotation(Modelica.Blocks.Continuous.LimPID)	0.483	0.123095
getComponentAnnotations(Modelica.Blocks.Continuous.LimPID)	0.431	0.0084116
getIconAnnotation(Modelica.Blocks.Continuous.Integrator)	0.333	0.0010419
getIconAnnotation(Modelica.Mechanics.Rotational.Interfaces.PartialTorque)	0.478	0.0022018
getComponentAnnotations(Modelica.Blocks.Continuous.Integrator)	0.441	0.0017218
getIconAnnotation(Modelica.Blocks.Nonlinear.Limiter)	0.444	0.0013694
Total	7.8	0.1378415

[casella]

Very good!

A small step for a man, a giant leap for openmodelicainterested :)

[adrpo]

Not yet fast enough thou', there is the other API that has impact. I'll have a look at that.

[casella]

True, but if I'm not mistaken, getIconAnnotation and getComponentAnnotations took the lion's share when opening a new model. Of course now some other function may, but it will still be much faster.

I'm not sure about getting the info to open parameter windows, but in my experience that has never been so painfully slow as opening a new model and visualizing it.

[anonymous]

Is it normal that the speedup is so lower in the first item in comparison with the others?
This table may hint (or probably not) that in the first case there are margins of improvement

	                                                                OF/NF time ratio
getIconAnnotation(Modelica.Blocks.Continuous.LimPID)	                      3.9
getComponentAnnotations(Modelica.Blocks.Continuous.LimPID)	               51
getIconAnnotation(Modelica.Blocks.Continuous.Integrator)	              320
getIconAnnotation(Modelica.Mechanics.Rotational.Interfaces.PartialTorqu       217
getComponentAnnotations(Modelica.Blocks.Continuous.Integrator)	              256
getIconAnnotation(Modelica.Blocks.Nonlinear.Limiter)	                      324

[adrpo]

The first call does the actual instantiation of Modelica.Blocks.Continuous.LimPID and caches it and also generic parts of it to be reused later (building of the lookup/inst structure, etc). That's why the next calls are so fast as quite a bit of what is cached is re-used.

[ceraolo]

Replying to adrpo:

Not yet fast enough thou', there is the other API that has impact. I'll have a look at that.

According to my tests, speedup opening models is indeed not so dramatic. Maybe because no all APIs have been updated?

For instance, opening

Modelica.Electrical.Machines.Examples.SynchronousInductionMachines.SMPM_VoltageSource

on my work PC immediately after loading OMEdit takes the following times:

old FE: 11.99s
-d=newInst, nfAPI: 7.02 s.

I tested this with OMEdit Connected to OpenModelica v1.14.0-dev-26494-g4d4d80992f (64-bit for Win)

[casella]

I checked the communication log with my PC. Opening the model with -nfAPI takes about 5 s, without it takes about 12 s. The current bottleneck is 'getExtendsModifierNames, which takes about 1.4 s in just 10 calls. Improving this 20x would bring down the time to about 3.5 s, which is more than an 3X speed-up compared with the old situation.

Other than that, it takes about 1200 API calls for the entire visualization task. At 3 ms on average, we already get 3.5 s. I don't see any other obvious bottlenecks, so I guess we'll need to make some more detailed analysis and carry out some focused optimization to improve on that.

But that will be once all bottlenecks have been removed, and probably for 2.0.0.

[adrpo]

The situation should be improved with f4dcc4b/OpenModelica.
Still some more work is needed to speed it up even more. Next on my list to use the NF: getComponents. The attached list is the API calls with execution time descending.

[casella]

Nice!

It would be interesting to also see the cumulated time once the calls are sorted in descending order, so we could figure out which calls are contributing to, say, 50% of the overall time.

[adrpo]

After using NF for getComponents, we get sorted6.txt

[adrpo]

As far as I can tell, to make it even faster we would need to group things together so we don't have so many calls, each consuming little.

[ceraolo]

Today with nfAPI on my PC opening

Modelica.Electrical.Machines.Examples.SynchronousInductionMachines.SMPM_VoltageSource

takes around 6s, so a 2x improvement over OF.

As a very early OMEdit adopter, I see this as very good news.
If I look at the thing with the eye of a future OM user, this time appears still a bit longer than expected.
So I hope the idea of grouping calls together is tried to see whether gives additional speed-ups.

I must add that in real-life opening time is much less an issue than what appears here.
In fact, only the first openings after OMEdit loading take this long: later model openings are much faster. For instance consider again

Modelica.Electrical.Machines.Examples.SynchronousInductionMachines.SMPM_VoltageSource

on my pc, opening it when OMEdit has just been started takes 6s. But if, instead, earlier I had opened

Modelica.Electrical.Machines.Examples.SynchronousInductionMachines.SMPM_CurrentSource

the same model is opened in just one second.

In past times (up to a few months ago), when OMEdit crashed frequently, every time one re-opened it, at first opening of models had to wait the long times for caching.
Today, that OMEdit is much more robust, the probability of working some hours without having to restart it is very high, so activities goo fast because as long as work proceeds OMEdit "learns" what it needs about the submodels being used.

This already existing "learning" feature suggests another idea. Maybe OMEdit could save somehow in the PC what has learned in the last session. So if (as common) one later starts working on a similar subject he will not have to wait the corresponding learning time again.

[ceraolo]

Just a further addition.
It looks like Dymola does something similar to what proposed in the last part of my comment 15:
upon opening MSL, it analyses everything, so that subsequent opening of models is very fast.

The notes regarding what already happens in OMEdit suggests that it is still able to reuse the information gathered from MSL in previous model openings. Maybe a strategy similar to dymola's can be considered?

[casella]

Replying to ceraolo:

Today with nfAPI on my PC opening

Modelica.Electrical.Machines.Examples.SynchronousInductionMachines.SMPM_VoltageSource

takes around 6s, so a 2x improvement over OF.

As a very early OMEdit adopter, I see this as very good news.

You are not alone :)

I must add that in real-life opening time is much less an issue than what appears here.
In fact, only the first openings after OMEdit loading take this long: later model openings are much faster. For instance consider again

Modelica.Electrical.Machines.Examples.SynchronousInductionMachines.SMPM_VoltageSource

on my pc, opening it when OMEdit has just been started takes 6s. But if, instead, earlier I had opened

Modelica.Electrical.Machines.Examples.SynchronousInductionMachines.SMPM_CurrentSource

the same model is opened in just one second.

This is because of caching. Which makes it a bit difficult to have meaningful figures when testing, because one should consider specific patterns of usage, and come up with some statistics, but I guess this is a bit too involved.

It would be good if you (and your students) use the tool a bit, and then get some subjective feedback, such as:

• I am happy with the responsivness of the tool
• The tool is ok but I would be happier if...
• In this specific situation I am really waiting too much, this must definitely be improved

The scenarios should be realistic use cases, not just opening one model with a freshly started OMEdit.

[casella]

Replying to ceraolo:

Just a further addition.
It looks like Dymola does something similar to what proposed in the last part of my comment 15:
upon opening MSL, it analyses everything, so that subsequent opening of models is very fast.

However, this means that every time you start Dymola, you need to wait about 30 seconds before actually starting to do real work. It's not that much, but if you need to restart the tool it is a bit annoying.

The notes regarding what already happens in OMEdit suggests that it is still able to reuse the information gathered from MSL in previous model openings. Maybe a strategy similar to dymola's can be considered?

I think that would be fine, as long as it is carried out on a parallel thread, while allowing to do other things in the meantime. I'm not sure how difficult it would be to implement such a strategy.

[ceraolo]

Replying to casella:

It would be good if you (and your students) use the tool a bit, and then get some subjective feedback, such as:

• I am happy with the responsiveness of the tool
• The tool is ok but I would be happier if...
• In this specific situation I am really waiting too much, this must definitely be improved

I already have such feeling.

As I said, caching joined with much higher OMEdit stability has improved things already.
Today's 2x first-loading speed-up enhances things more but, IMO, they are still sub-optimal.
So, AFAIC, some more attempts to further reduce first-time loading speed are worth while. Naturally, it is a question of cost/benefit ratio.

There are several ideas: grouping calls together, saving cache of open models before closing OMEdit, automatic caching of MSL...
Maybe some of them can give a good cost/benefit ratio.

Obviously, some feedback from other users can help.

About my students. I promised two additional marks at the exam for each repeatable bug found. Two students this semester gained the two-mark-award! (tickets #5400 and #5434)

[casella]

Replying to ceraolo:

So, AFAIC, some more attempts to further reduce first-time loading speed are worth while. Naturally, it is a question of cost/benefit ratio.

Sounds good.

In fact, the original main goal of 1.14.0 was to overcome historic shortcomings of OMEdit, namely: missing support of replaceable (#2079), properly updated parameter-dependent enable annotations (#2661) and support of conditional connectors (#2081). These features are widely used by the MSL and other libraries, missing them makes OMEdit awkward to use on a large subset of existing Modelica models.

We also have the goal of making OMEdit more responsive, but I think that a significant improvement has already been achieved, and we should first focus on the above-mentioned issues, with the goal of releasing 1.14.0 before the summer break. Further improvements in responsiveness can end up in version 2.0.0, later this year.

[casella]

Replying to adrpo:

After using NF for getComponents, we get sorted6.txt

I checked the list.

getComponents() is quite slow on several occasions. I guess this is still using the OF. As the number of components in the MSL examples is normally a few dozens at most, I wonder why getting such a short list of component names should take so long. BTW, this function is missing in the ​documentation, so I don't know exactly what it does.

getMessageStringInternal() and size(errors,1) are called several times and take several hundred milliseconds. I would expect these to be stupid operations that can be carried out in a few milliseconds, why isn't this the case?

[adrpo]

Actually, we do use the NF for getComponents now and *it is slower* than before most of the times, that is because we instantiate the class where we query the components from, in order to be able to lookup the type of each component and then fully qualify it. I find it strange that is this slow, so I'll investigate a bit if we can speed this up. One avenue to explore is disabling parts of the instantiation (as we don't need it) such as handling sections (for lookup we don't need to instantiate the equations/algorithms in the model/package but currently it is implemented like that).

[casella]

OK. If this gets complicated, I would suggest to prioritize the goals in comment:20

[casella]

I'll mark it as a blocker for 2.0.0. IMHO we have already enough speedup for 1.14.0, after all we didn't promise anything there regarding performance.

[ceraolo]

Replying to casella:

However, this means that every time you start Dymola, you need to wait about 30 seconds before actually starting to do real work. It's not that much, but if you need to restart the tool it is a bit annoying.

On MY PC's the situation is totally different. On My home PC, from which I'm writing, caching the whole Modelica (starting from a just-rebooted Win 10 and just-loaded Dymola 2018 FD01)) takes below 0.8s. Even if this in OM becomes 20 times this figure (say 15 s), this caching would greatly improve the user experience since this is just a one-per-session time.