flick() using insane amounts of CPU

ID:1747751
 
Dec 26 2014, 5:41 pm
Resolved
flick() had some inefficient code.
BYOND Version:507
Operating System:Windows 7 Home Premium 64-bit
Web Browser:Chrome 39.0.2171.95
Applies to:Dream Daemon
Status: Resolved (507.1273)
This issue has been resolved.
Descriptive Problem Summary:

flick() is really unoptimized or has something wrong with it.

To make built in functions appear in the cpu profiler (.debug profile) so that I can measure their impact on my game I placed them all in wrapper functions. See the code example.

And I will use those wrapper functions everywhere in my code in place of the built in function name

And this reveals that flick() uses the most CPU time in my game by far, even though all it is used for is when a player uses the punch command. So you have 100 players with about 20% of them fighting at any time, each able to attack about 2 times a second at the most, so flick() is being used AT MOST 40 times per second in the game. These are high estimates.

And here is what it looks like in the profiler:

Image and video hosting by TinyPic

You can see it is closely followed by sleep()'s wrapper function which is called Sleep(). And then every function I have written myself uses far less than flick() which is pretty ridiculous

Numbered Steps to Reproduce Problem:
I would guess you just call flick() like 50 times a second and watch it use way more cpu than it should, maybe it depends how many players are on.

Code Snippet (if applicable) to Reproduce Problem:
proc/Flick(i,atom/a)
    flick(i,a)


Expected Results:
flick() uses a reasonable amount of cpu

Actual Results:
flick() uses more cpu than ANYTHING in my game (Dragon Universe) which is a huge game with a lot of code so the fact that flick() is at the top of the profiler is pretty insane when it is so conservatively used (It is only when a player punches)

Does the problem occur:
Every time? Or how often?
In other games?
In other user accounts?
On other computers?

When does the problem NOT occur?
When you don't use flick()

Did the problem NOT occur in any earlier versions? If so, what was the last version that worked? (Visit http://www.byond.com/download/build to download old versions for testing.)

Workarounds:

Maybe if I code my own version of flick()
Dec 26 2014, 5:42 pm
What does the profiler look like with Average ticked?
Dec 26 2014, 5:48 pm (Edited on Dec 26 2014, 5:58 pm)
Image and video hosting by TinyPic

Also you can see that Flick() was called 112,000 times in a 15 minute period, so that comes out to flick() being used 120 times per second, but we have 120 players online so that is only 1 time per second per player.

Ticking average shows that SaveWorld(), which in itself calls MapSave(), SaveItems(), Save_Misc(), Save_NPCs() (most of those are also on this picture of the profiler) and a whole bunch of other save functions, is at the top. But SaveWorld() only occurs once every 30 minutes.

I don't think having average ticked is really relevant to this example.
Dec 26 2014, 6:01 pm
You can see in the profiler that Sleep() is in second place. This is pretty much my own fault because I overused sleep() in my game, allowing many functions to wait when they aren't needed, instead of doing it right and only calling those functions when needed in the first place. I did this because I was told that sleep() has "virtually no overhead" which from what I can tell is completely untrue from those profiler results.

I didn't use something insane like sleep(1) all over the place, but when a function needs to wait it usually has sleep(30) or so depending on what it is waiting on. For example Recover_health_loop() is on every player and if their health is >=100 then the loop will just do sleep(50) until it falls under 100 and then heal for example +1 every sleep(10)
Dec 26 2014, 9:44 pm
I didn't find much in flick() that would appear to be very heavy on time, except there was one unnecessary function call that could be eliminated. I do think that changing that will make a dent in your results, but I expect there's more going on than that. I found something in the message builder as well, but it was quite minor.

A flick is sent to all clients to ensure everyone has a correct state. This wasn't always the case, but it solved a lot of problems. This fact could could be relevant, because if you have a lot of players all flicking very frequently you effectively have an O(N^2) operation. (Likely as not, the old way was worse anyway.)

The sequence of events followed is basically this:

- Build the flick message; this involves examining both args to see what needs to be put into the message.
- Send a message to every client telling it the identity of the atom being flicked (important for cases where objs/mobs get recycled frequently, but skippable for the webclient).
- Broadcast the message to everyone.
- Check to see if the atom is an obj or mob with a screen_loc; this may be redundant now and might also be a place flick() can be trimmed down.

A lot of what I found is really minor, but could add up to some savings. I'm not sure if anything else can be trimmed beyond that.
Dec 26 2014, 10:47 pm
Do you think using animate() instead of flick() would be an improvement?
Dec 26 2014, 11:17 pm
I'll try that but from the looks of it that will just be even slower
Dec 27 2014, 2:41 pm
I suspect flick() is the better choice for these simple cases.
Dec 28 2014, 2:40 pm (Edited on Dec 28 2014, 2:59 pm)
Does me using flick() via a wrapper function result in roughly the same actual cpu usage that using flick() by itself in the code would?

Or by creating a wrapper function for it have I somehow inflated the cpu usage of my game?

And do you have any thoughts on this "problem" and do you think it is something you can or will fix?

What if you made BYOND cache the result of flick when the same operation is requested repeatedly and then bypassed any extra calculations, would that do anything? Because I am literally requesting the same result over and over. flick("attack",player), when players usually share the same icon.
Dec 28 2014, 7:22 pm
In response to Lizard_Sphere_X
Lizard_Sphere_X wrote:
Does me using flick() via a wrapper function result in roughly the same actual cpu usage that using flick() by itself in the code would?

Or by creating a wrapper function for it have I somehow inflated the cpu usage of my game?

Calling a proc will incur some overhead for sure. Basically the args have to be stored, and then the proc call is made, and various housekeeping at the beginning and end of the proc is also done. Then the args have to be loaded again before they're used in the actual flick instruction. Only some of the pre- and post-proc overhead gets measured in profiling, though it would show up in the calling proc.

And do you have any thoughts on this "problem" and do you think it is something you can or will fix?

The issues I found are easily fixed. Most of them are minor, except that I believe the check for screen_loc is completely unnecessary and is probably the biggest potential savings. I'd just want to test to be sure it didn't break anything.

What if you made BYOND cache the result of flick when the same operation is requested repeatedly and then bypassed any extra calculations, would that do anything? Because I am literally requesting the same result over and over. flick("attack",player), when players usually share the same icon.

No calculations are really done there, server-side except for how to form and send the message. There's nothing to cache except the message, and any overhead involved in looking it up in a short-term cache would far eclipse the effort of building the message in the first place.
Jan 2 2015, 12:18 pm
Lummox JR resolved issue with message:
flick() had some inefficient code.
Jan 2 2015, 12:38 pm
In response to Lummox JR
Lummox JR wrote:
Lummox JR resolved issue with message:
flick() had some inefficient code.

If by chance flick() had inefficient code, could there be a few other things the majority use that you could take a glance at? xD

Just for the sake of it?
Jan 2 2015, 12:45 pm
In response to Kozuma3
I'm an optimizing fiend. I've looked at all kinds of code looking for ways to improve it; the flick() code was just something I hadn't noticed, but I did find three separate things to improve:

1) There was a lookup of the object's container that was no longer actually necessary.
2) In the message construction, procs were called that got an obj or mob ID with type checking, even though the type was known because it was in a switch.
3) Objs and mobs were being checked for screen_loc and a flick was sent for those specially, even though the change that sent the flick to all users made it unnecessary.

Change #3 is where I expect the biggest improvement, though #1 is probably pretty good too since there was really no need to look up the object's loc anymore. Bear in mind that flick() is already very fast, and much of the profile timing that we saw was due to 1) proc overhead, and 2) the very high number of calls.
Jan 5 2015, 2:09 am
Thanks Lummox, if I could update my game to the latest beta yet, I would let you know the results, maybe I will be able to soon.