The performance seem dropped twice since last year

[rendetto]

I'm doing a pass on all setups I worked on the past few years, searching for bugs and broken things in the current Sverchok master. Unfortunately it seems that for the past year the performance of Sverchok dropped twice concerning this particular setup:

The problem doesn't seem to be in the current code of NURBS Sweep, because I deliberately reverted it to match the one from Apr 2021 and it doesn't matter what calculations it's doing - it's just twice as slow in master. So it should be somewhere else. Maybe in the update system? @Durman I've seen you making detailed studies on the node performances, can you please take a look at this?

I'm uploading the file for examination: Sweep_Precision_Symmetry_TestSpeed.zip

Thanks

[portnov]

Can you point a commit at which performance was "good"?

[rendetto]

This is the one I used for the testing 8bef7918a6bcbb05772c040bbbb189b4b27f5eb8\ It runs under official Blender2.90.0 (pyton 3.7), win10 x64. I'm not sure that I can find the breaking point commit, but I can try.

[portnov]

Theoretically it should be easy enough, using git bisect. The only problem can be is that your file probably will not load on old blender :/

[rendetto]

I'm using several Blender versions for those purposes. I'm on it. It just will take some more time because I do those things manually x_x (need to learn about git bisect).

[portnov]

Hm. I just loaded your file on blender 2.90 with https://github.com/nortikin/sverchok/commit/8bef7918a6bcbb05772c040bbbb189b4b27f5eb8, and on 3.3.1 with master. I see no difference: for both, tree update takes about 66 ms. What are your results? Can you provide profiling data for "good" and "bad" cases?

[rendetto]

Ummmm... thats weird. Same scene, same Sverchok revision:

Blender 2.90.0 - 25fps DEBUG:sverchok.core.update_system:Node set updated in: 0.0332 seconds

Blender 2.93.9 - 11fps but again: 2022-11-25 18:18:49,567 [DEBUG] sverchok.core.update_system: Node set updated in: 0.0307 seconds

I don't know what to think :/

EDIT: Ah... when I start debug to the console on Blender2.90.0 the performance dropped to 11fps also. So printing in the console is not something reliable for referencing the performance. When I turned off the debug printing timings in the console Blender 2.93.9 shows also 25fps - the same performance as 2.90.0

so it is like that: Blender 2.90.0: ~11fps, SV commit https://github.com/nortikin/sverchok/commit/8bef7918a6bcbb05772c040bbbb189b4b27f5eb8, print timings ON: DEBUG:sverchok.core.update_system:Node set updated in: 0.0332 seconds

Blender 2.93.9: ~11fps, SV commit https://github.com/nortikin/sverchok/commit/8bef7918a6bcbb05772c040bbbb189b4b27f5eb8, print timings ON: DEBUG:sverchok.core.update_system:Node set updated in: 0.0307 seconds

Blender 2.90.0: ~25fps, SV commit https://github.com/nortikin/sverchok/commit/8bef7918a6bcbb05772c040bbbb189b4b27f5eb8, print timings OFF

Blender 2.93.9: ~25fps, SV commit https://github.com/nortikin/sverchok/commit/8bef7918a6bcbb05772c040bbbb189b4b27f5eb8, print timings OFF

and lastly Blender 3.3.1: ~13fps, SV master, print timings not available, but displayed in the node editor:

I'll continue searching for the breaking point commit and report.

[portnov]

@rendetto https://git-scm.com/docs/git-bisect

Basically you do:

git checkout master

git bisect start 8bef791

it switches you to the version halfway between master and that commit. Then you run blender and check performance. If you like it, you say git bisect good; otherwise, you say git bisect bad. It switches you to some other revision, you check it again. After some iteration, git will guide you to the point where everything changed.

[Durman]

Also position of the cursor can effect the performance during animation =)

[rendetto]

Thanks @portnov I was doing almost the same thing but manually :)

[portnov]

The thing is, since it divides the segment between commits by two each time, you will find the problematic commit in O(log(n)) steps instead of O(n) if you check each commit. That can be much faster.

[rendetto]

you will find the problematic commit in O(log(n)) steps instead of O(n) if you check each commit. That can be much faster.

Valid point

[rendetto]

Also position of the cursor can effect the performance during animation =)

What I'm doing while looking at the fps is moving the selected vertex in the viewport.

My focus of using Sverchok is mainly at researching the Direct NURBS Modelling capabilities of the system, that's why I'm so sensitive about those fps.

[rendetto]

Found it! In fact there should be several drops but I found the first significant one.

Blender 2.93.9: ~25fps, SV commit https://github.com/nortikin/sverchok/commit/c034f1729ef375495f57fa87e829c41566c299f3 Blender 2.93.9: ~16fps, SV commit 2b26e66bdfdc477ec5286da9ddabccedd83a9670

The performance these days is like that: Blender 2.93.9: ~12fps, SV commit f6676511e124811e16b2f9ff7fc9f4e64d616b22

[portnov]

Well, yeah, using inspect is slow. @Durman can we remove it? https://github.com/nortikin/sverchok/commit/2b26e66bdfdc477ec5286da9ddabccedd83a9670

[rendetto]

Found the second drop.

From ~16fps at: Blender 2.93.9: ~16fps, SV commit cf7245cb23acdde9a4e1ad808848ed64081f3fb5

Dropped to ~13fps at: Blender 2.93.9: ~13fps, SV commit 1225957f1d9ebac835d743cc1228edaa185ad6e9, started from 66a4cfbbf8fecd8537b1fc2013d8ad5b573a4763

Then there are several commits that are at 6fps (due to some debug prints) until again: Blender 2.93.9: ~13fps, SV commit 3cf3f62c10dc87f8e67d7b5cb4420e6552b058c8 and that persists to this date.

[Durman]

I guess we should try something like this:

def debug(self, msg, *args, **kwargs):
+    if is_debug_level:
        self.get_logger().debug(msg, *args, **kwargs)

And the same for other log methods

[Durman]

@rendetto I've added optimizations into master. Can you check whether it was helpful?

[rendetto]

@Durman Thanks a lot! Just tested and we're about ~20fps now!

@Portnov did you manage to take a look at the second drop I found https://github.com/nortikin/sverchok/commit/1225957f1d9ebac835d743cc1228edaa185ad6e9 ?

[portnov]

not yet

[portnov]

@rendetto strange. For me,

• at https://github.com/nortikin/sverchok/commit/1225957f1d9ebac835d743cc1228edaa185ad6e9, total recalculation of the tree you attached in the beginning, takes about 90ms;
• at previous commit, cf7245c, update takes ~60ms — so it seems you were right, that commit made things slower.
• But, in current master, it also takes 60ms!

Can you check?

[portnov]

However, I was able to find a place where it did get slower: new curve interpolation code was more generic, and, as such, it was executing more computational-heavy code for interpolation of rational curves, even when the curve was non-rational. I added a check for this to run more fast version of code for simple case in #4805. Please check.

[rendetto]

@portnov Just checked. And yes, with https://github.com/nortikin/sverchok/pull/4805 we gained more speed.

I seems that with https://github.com/nortikin/sverchok/issues/4772 and https://github.com/nortikin/sverchok/pull/4805 the performance drops are cleared out :)

Thanks a lot!