ID:1860571
 
Resolved
Looping through atoms in area contents was painfully slow.
BYOND Version:507
Operating System:Linux
Web Browser:Chrome 40.0.2214.111
Applies to:Dream Daemon
Status: Resolved (509.1306)

This issue has been resolved.
The below was tested with BYOND 507.1285.

Descriptive Problem Summary:
When used on /area, locate() takes significantly longer than expected to locate objects when the area is relatively full (one object per turf in a 50x50 area is more than enough). It locates them correctly, it merely takes a long time to do so. Defining a proc to loop over all turfs in an area, calling locate() on each, executes faster.

Numbered Steps to Reproduce Problem:
Create an area with at least ~250 objects in, and at least one of a specific type of object.
Call locate(TYPE) in AREA, observe that it takes potentially several seconds to execute.
Call locate(TYPE) in world, observe that it takes almost no time.
Call the below proc_locate(TYPE, AREA), observe that it also takes almost no time.

Code Snippet (if applicable) to Reproduce Problem:
/world
maxx=50
maxy=50
maxz=1

/world/New()
for(var/x = 1 to world.maxx)
for(var/y = 1 to world.maxy)
for(var/z = 1 to world.maxz)
new /obj(locate(x,y,z))

/obj/find

/proc/proc_locate(type, area/A)
for(var/turf/T in A)
. = locate(type) in T
if(.) return

/client/verb/test()
var/area/A = locate(/area)
var/obj/find

var/x = 1
var/y = 1
var/z = 1
for(var/i = 0 to 7)
if(i&1) x=world.maxx; else x=1
if(i&2) y=world.maxy; else y=1
if(i&4) z=world.maxz; else z=1
find = new /obj/find(locate(x,y,z))
var/start = world.timeofday
var/t = locate(/obj/find) in A
var/end = world.timeofday
world << "locate at [x],[y],[z] took [end-start] ds (found [t])"

start = world.timeofday
t = proc_locate(/obj/find, A)
end = world.timeofday
world << "proc_locate at [x],[y],[z] took [end-start] ds (found [t])"

del(find)


Output of the above code on my machine (with the duplicate min-z and max-z results removed):
locate at 1,1,1 took 0 ds (found the find)
proc_locate at 1,1,1 took 0 ds (found the find)
locate at 50,1,1 took 4 ds (found the find)
proc_locate at 50,1,1 took 0 ds (found the find)
locate at 1,50,1 took 228 ds (found the find)
proc_locate at 1,50,1 took 0 ds (found the find)
locate at 50,50,1 took 233 ds (found the find)
proc_locate at 50,50,1 took 0 ds (found the find)


In a table:






x y locate() (seconds) proc_locate() (seconds)
1 1 0 0
max 1 0.4 0
1 max 22.8 0
max max 23.3 0


Expected Results: locate() in area would be as fast as if not faster than an equivalent proc that loops over turfs in the area and calls locate() in turf on them

Actual Results: locate() in area is incredibly slow.

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

When does the problem NOT occur? When using proc_locate(), or when not using locate() to search areas

Did the problem NOT occur in any earlier versions? If so, what was the last version that worked? Unknown

Workarounds: Use proc_locate() for searching areas.

That's a very interesting result, especially since the locate() code internally is basically doing exactly what your proc does--the hard code ought to be faster.

I would however recommend retesting this in a way that runs tests on the same object and proc multiple times through a loop and accumulates the results, because the timer resolution is not very high.
I'm currently running a test in a 150x150x10 area, at which point proc_locate() starts to have non-zero timings. So far I know the result for an object at 1,1,1: 1041 deciseconds.
Oh man, I think I can explain this. I think the lookup is definitely very inefficient for areas, because here's what it's doing:

There's a function called FindTypeIn() that calls InitListIndex() and then GetNextListItem() using a list iterator. The iterator then has to look up the right value by its position in the list. This is not the most efficient way to handle any contents list, because turf/obj/mob contents are each a pair of linked lists (one for objs, one for mobs). But for most atoms that's not an issue because the contents list is small. Not so areas. (BTW, doing an "X in Y" check when Y is an area would be the same deal, just with a different function.)

Areas don't store their contents in any kind of convenient way, so looking up an item by index basically means it has to recreate the list every time. This is an O(N^2) operation and highly inefficient. For most objects this is really not a concern; the issue is when areas are in play.

As a workaround, you can do this:

locate(/obj/find) in A.contents.Copy()

The code in question actually impacts a lot of things, including output, so I think by solving this I could probably improve performance in games that use "in area" quite a bit.
Lummox JR changed status to 'Verified'
It occurs to me I can probably make a significant improvement on this simply by allowing area.contents to return results in a different order and altering the way it iterates. That would avoid the need for any logic to see if the list should be copied.
In my experience with ss13 code atleast, locate() is almost always slower than looping manually. One example, a get_turf() proc would get the actual turf of a thing and return it, doing locate(/turf) in thing.locs is slower than recursive lookup on thing

get_turf(const/atom/thing)
if(isnull(thing) || isarea(thing)) return

var/atom/A = O

for (var/i = 0, i <= 16; i++)
if(isturf(A)) return A
if(istype(A)) A = A.loc
else return

In response to Pomf123
Considering infinite recursion shouldn't be possible, you could trim that loop for speed:

for(var/atom/A=O, A && !isturf(A), A=A.loc);  // semicolon is for the empty statement
return A

Are there a lot of spots in SS13 (at least the codebase you use) that use "in area"? If so I think my fixing this issue could potentially cause big improvements.
In response to Lummox JR
Lummox JR wrote:
Considering infinite recursion shouldn't be possible, you could trim that loop for speed:

for(var/atom/A=O, A && !isturf(A), A=A.loc);  // semicolon is for the empty statement
> return A

Are there a lot of spots in SS13 (at least the codebase you use) that use "in area"? If so I think my fixing this issue could potentially cause big improvements.

Correct me if i'm wrong but the way i interpret that loop is

So long as A exists, and is not a turf, Return A, then A is = to A.loc
In response to Pomf123
That is wrong, because return A operates after the loop.

This says: As long as A exists and is not a turf, do nothing, then set A=A.loc. After the loop is finished (at which point A is either null or a turf), return A.
Oh i understand now, its an empty loop. I somehow missed the semicolon bit.
I find this report humorous as I also found this out but never once considered it a bug just a quirk of locate() being slow.

Our SS13 codebase ran into this exact problem from a proc locating a specific object within an area using "locate(type) in area" and ended up removing it in favor of keeping it stored in a variable, but I'm sure many others still have yet to remove it or other procs like it.
SS13's get_apc() proc was actually the cause of this report, see https://github.com/Baystation12/Baystation12/issues/9536
In response to Lummox JR
Lummox JR wrote:
Considering infinite recursion shouldn't be possible, you could trim that loop for speed:

I tested this, and I don't like how byond handles this.


O1.loc = O2
O2.loc = O1

This should runtime, but it doesn't, it just sets O2's loc to null, with no runtime or warning. Meaning the programmer has no easy way of figuring out why O2.loc's is null.

In the example above, it's easy to figure out, but in a complex project where you have multiple nests of an object, each nested object defined in their own file, a typeo or minor logic error could easily lead to a recursion attempt happening, with no obvious sign to the programmer that they fucked up, or where.

Old issue, but still present as of 508.1299, if anything worse than back in 507; what used to time as proc_locate 1ds, locate 1041ds (locating an object at 1,1,1 in a 150x150x10 world) now times identically (1ds) for proc_locate, but takes almost 2400ds for locate.
I have doubts this would be any worse for 508, because the code responsible has not been changed in any way yet. More likely you're seeing normal variation in the timing and the margin of error is high.
Hey, do you have a copy of your test project? That'd be really helpful to me because I want to test the change I'm making.
My test project is the source in the initial post, just tweaking the world.max[xyz].
Okay, thanks. I'll play with that and see if my tweak fixes it.

Basically I'm modifying the list iterator, length, and index read routines to handle area contents specially.
Results from before the change, in release mode:

locate at 1,1,1 took 0 ds (found the find)
proc_locate at 1,1,1 took 0 ds (found the find)
locate at 50,1,1 took 15 ds (found the find)
proc_locate at 50,1,1 took 0 ds (found the find)
locate at 1,50,1 took 672 ds (found the find)
proc_locate at 1,50,1 took 1 ds (found the find)
locate at 50,50,1 took 799 ds (found the find)
proc_locate at 50,50,1 took 0 ds (found the find)
locate at 1,1,1 took 1 ds (found the find)
proc_locate at 1,1,1 took 0 ds (found the find)
locate at 50,1,1 took 15 ds (found the find)
proc_locate at 50,1,1 took 0 ds (found the find)
locate at 1,50,1 took 696 ds (found the find)
proc_locate at 1,50,1 took 0 ds (found the find)
locate at 50,50,1 took 701 ds (found the find)
proc_locate at 50,50,1 took 0 ds (found the find)

After the change, in debug mode which is slightly slower:

locate at 1,1,1 took 0 ds (found )
proc_locate at 1,1,1 took 0 ds (found the find)
locate at 50,1,1 took 0 ds (found )
proc_locate at 50,1,1 took 0 ds (found the find)
locate at 1,50,1 took 0 ds (found )
proc_locate at 1,50,1 took 0 ds (found the find)
locate at 50,50,1 took 0 ds (found )
proc_locate at 50,50,1 took 0 ds (found the find)
locate at 1,1,1 took 0 ds (found )
proc_locate at 1,1,1 took 0 ds (found the find)
locate at 50,1,1 took 0 ds (found )
proc_locate at 50,1,1 took 0 ds (found the find)
locate at 1,50,1 took 0 ds (found )
proc_locate at 1,50,1 took 0 ds (found the find)
locate at 50,50,1 took 0 ds (found )
proc_locate at 50,50,1 took 0 ds (found the find)
Page: 1 2