Page 1 of 1

Updated widget/gadget profilers

Posted: 15 Apr 2018, 14:31
by Silentwings
I updated the profilers to display statistics about the memory allocations of each widget/gadget/callin, beautified their UIs & cleaned their code. Thanks to Kloot for Spring.GetLuaMemUsage!

Files are attached below. They will only work with the "classic" widget/gadget-handlers, and need Spring 104.0.1-409 (maintainence) or later.

BA with some KAIs and all units selected (widget profiler):
Image
BA with one unit on map (gadget profiler):
Image

Re: Updated widget/gadget profilers

Posted: 15 Apr 2018, 22:55
by hokomoko
This is ridiculously amazing!

Re: Updated widget/gadget profilers

Posted: 16 Apr 2018, 23:44
by Silentwings
New version & updated the OP, because:
- re-added a way to switch off the gadget profiler, see notes in file
- reports the total lua mem usage of different states (again, thanks Kloot!)

I think I'm done playing with this now.

Re: Updated widget/gadget profilers

Posted: 17 Apr 2018, 07:07
by Google_Frog
screen00014.jpg
(726.99 KiB) Not downloaded yet
Can you explain the discrepancy with the previous profiler? For example, yours says that priority is around 1% while the previous profiler says 2.7%.

Re: Updated widget/gadget profilers

Posted: 17 Apr 2018, 08:40
by Silentwings
What is the 'priority'? I've not heard this terminology before.

I can't read parts of the text from your profiler within the screenshot, it's too small (use /screenshot png to avoid lossy).

edit: Running two profilers at once is a bad idea, see my next post.

Re: Updated widget/gadget profilers

Posted: 17 Apr 2018, 08:47
by hokomoko
It may not be the reason but remember that one profiler also measures the work of the other profiler.

Re: Updated widget/gadget profilers

Posted: 17 Apr 2018, 08:52
by Silentwings
Possible explanations for what you're seeing:

(1) The tick (-> recording interval) time and averageTime (->relative rate at which new data is weighted over old):

https://github.com/ZeroK-RTS/Zero-K/blo ... r.lua#L327 vs
https://github.com/ZeroK-RTS/Zero-K/blo ... w.lua#L374
(The common update rule: https://github.com/ZeroK-RTS/Zero-K/blo ... w.lua#L387)

The random variations caused by this will be more pronounced in cases where the raw data is an erratic function of time, which is the case for some gadgets (if gameFrame%30~=0 etc etc). The long term averages over all time would be the same, but profiler doesn't report those.

All the other reasons I can suggest are side effects of trying to run two 'hook based' profilers on top of each other (doing that should not be expected to give matching output):

(2) With both profilers running at once, whichever one started first will have its hooks contained *inside* the other ones hooks. So one (and only one) of the profilers will actually count the time that the other one is taking to run its data recorders. The differences caused by this will be felt everywhere, but are likely to be huge for gadgets containing callins that are called very frequently e.g. during a big game AllowUnitBuildStep is called insanely often.

(3) The profilers exclude their own callins running times but, when you run two at once, they will not exclude the running times of each others callins. Since the time figures are reported as '% of total callin running time' this will cause a scaling factor difference between the numbers reported by each profiler. This effect will be strongest during a low-stress game with a high draw callin rate, because the profilers own draw callins (which contain ~all the non-hook code) are very expensive due to being (deliberately) non-optimized. My one gives more info on-screen and has the more expensive draw callin of the two; also their cost depends on tick time.

[In your screenshot, I'd give a careless estimate of the scaling factor in (3) at ((3.28%/24%)/2+1) which is about 1.06. It looks like a heavy sim load and a low-ish fps, so I'd expect that (2) is the biggest magnitude effect that you're seeing, but that (2) only affects a subset of the heavier gadgets, and random small variations everywhere are primarily due to (1).

Btw, your screenshot shows 0kB/s allocs for all synced luarules. I guess something is wrong there - in BA my profiler records a couple of hundred kB/s for synced luarules during a game. It might be some complicated consequence of running multiple profilers at once, or something caused by ZK, idk.]