BOY performance issues with scripts because of pvmanager max-update-rate

[shroffk]

On linux machines with gtk+ version 2.20.1-2
The use of scripts/rules has a significantly degraded performance that 3.1.x

I have attached 2 test screens the first has a 100 widgets with connect to a sim://noise pv. While running the screen we have a CPU load of approx 18%.
The second screen has the same 100 widgets with rules attached which connect to sim://noise, when running this OPI we see a load of 200%.

I was unable to reproduce the same problem on a windows machine.

[xihui]

I didn't see the attached OPIs. Could you use profiling tool to see what's using CPU?

[shroffk]

https://drive.google.com/?tab=mo&authuser=0#folders/0Bxrrhhn0aTLWRmd2ZXI1bWFMMEU

Sorry I forgot to add the link.

When we looked at the dump most of the time was spent in the timer thread.

[xihui]

I cannot reproduce it on my redhat linux 6. Could you use jProfiler to see which methods are using the most CPU?

[kasemir]

Not sure what we are comparing here, because the displays do some different things.

perf_test.opi displays LEDs that change their alarm state. On OS X, I see a CPU load of ~2%, peaking to 10% every 10 seconds.

perf_test_rule.opi doesn't display anything, but a rule changes the widget's name. On OS X, I see a CPU load of 6% peaking to 12% every 10 seconds.

CPU load in both cases is the jProfiler info.

The first case is Java code for handling the values, resulting in display redraws, which goes into native code.
The second case is a lot more Java code because of the Rule/Script.

Does the "name" property update trigger a widget redraw, which is almost a NOP on Windows and OS X, but with GTK it shows that drawing can be very slow on Linux? I don't see it executing redraw code on OS X for the perf_test_rule.opi.

[kasemir]

On my RedHat EL 6.4 computer, CPU loads are ~10% resp. 70%, so it really is a lot more CPU usage on Linux for the perf_test_rule.opi.

jProfiler shows many calls to AbstractScriptStore..run(), which ends up in widget.setPropertyValue(), but that's not using any CPU.

The CPU usage is in pvmanager.PVReaderDirector.notifyPv calling concurrent.Executor.execute(), from which it currently doesn't show further calls.

[shroffk]

Ok,
I uploaded 3 snapshots to the same folder, the first which is when cs-studio starts, the second is for the perf_test.opi and the third is the perf_test_rule.opi

[xihui]

Could you change the PV connection to utility pv and try again?

[kasemir]

What's happening in the code basically looks OK:

pvmanager.PVReaderDirector.notifyPv calling concurrent.Executor.execute()
That execution then happens on the UI thread, and what it's doing is call AbstractScriptStore..run(), which ends up in widget.setPropertyValue().
BOY scripts run on the UI thread so that they can affect the UI.
The execution of the script actually doesn't take much time, and on Windows and Mac OS X all is OK.

I assume the issue is that the UI thread is somewhat special. It involves native code for the UI (SWT) event loop, and on Linux that's for some reason slow.

[kasemir]

With utility_pv, CPU loads are ~10% for perf_test.opi and 8% for perf_test_rule.opi, so the problem goes away.

The execution path is similar: util.pv sends a new value, script receives valueChanged(), transferring to UI thread for executing the script.

There must be some key difference between going from the network thread to the UI thread for pvmanager and util.pv.

[xihui]

I also caught it on my redhad linux machine. It looks like PVReaderDirector.notifyPv was called a lot (about 10,000 times/second). Since there is only one pv (sim://noise) on the OPI, I'm wondering why it is call so frequently.

[kasemir]

Yes, that's it. Sorry I didn't notice the invocation counts.

Util PV treats sim://noise as one PV, while PVManager must basically create one such PV per widget (100), plus maybe it's then 'checking' for new values at the max update rate?

[xihui]

OK, I got the reason, the maximum update rate for the PV of scripts/rules was set to 50hz. That is because the scripts/rules should be notified on every PV value change as possible as it can. Unfortunately, PVManager will notify on the maximum rate which is set while creating the PV instead of the update rate of the PV itself.

[kasemir]

I think this can be files as 'won't fix':
It's a known pvmanager feature that max update rate isn't perfectly handled.
This test case nicely shows that, but the example isn't super realistic because you won't display the same channel 100 times this way.

In the real world, there could of course be an example with 100 different PVs which really have useful value changes. In that case, I'm not sure a rule needs to be triggered at 50Hz. 10Hz would be fast enough to reflect the 'current' value of the PV.

[xihui]

I'm not sure what to do, for a script that aims to statistic number of updates, 10Hz might not be enough. The ideal way is that PVManager can call notifyPV at the lower one between set rate and the update rate of the PV itself.
Hi Kunal, could you create a new issue on PVManager for this issue?