Critical bug with Collectionfactories (DEF-2661) (SOLVED)

Bugs
#1

As we are creating some complex fx with compositions of gameobjects I am using Collectionfactories to spawn them on their positions (can be say 2-3 gameobjects with spine, particles, spriteanimations etc).
For a long time I have had a weird stuttering in the game every, say 3-4 second, becoming worse and worse as the game runs.
Now when Ive tried everything else it actually is the collectionfactories that is behaving really weird at creation.
If creating lots of collections over time once in a while the factory will take very long time to be created. This stutter will increase in length every time it spikes. Starting from humble 0.001s to 0.5 s and beyond.

I would definitely say it’s a major bug and I have now (as we are short of time) chosen to create my own compositions of normal gameobject factories. The stutter disappeared immediately.
The freeze stops everything including audio.

So I have created a testcase and it is proving the bug:

local DELAY = 0.2
local MED_FACTOR = 4
function init(self)
    self.timer = DELAY
    self.med_time = 0.0002
end

function update(self, dt)
    self.timer = self.timer - dt
    if self.timer < 0 then
    	local st = socket.gettime()
    	collectionfactory.create("/factories#collectionfactory", vmath.vector3(math.random(400),math.random(400),0))   	
    	st = socket.gettime()-st
    	if st/self.med_time > 10 then
    		print(st)
    	end
    	self.med_time = (self.med_time * MED_FACTOR + st)/(MED_FACTOR+1)
    end
end

The script is creating a collection (with a single gameobjec w. particlesystem in it, so nothing complex) every update. Every 2 second it will spike and print out a creationtime 10 times higher than the other normal ones (which lies around 0.0002 s)
This is the start of the output which you can see is increasing in creationtime:
DEBUG:SCRIPT: 0.071110963821411
DEBUG:SCRIPT: 0.089191913604736
DEBUG:SCRIPT: 0.093577146530151
DEBUG:SCRIPT: 0.095737934112549
DEBUG:SCRIPT: 0.090879201889038
DEBUG:SCRIPT: 0.098695993423462
DEBUG:SCRIPT: 0.11932301521301
DEBUG:SCRIPT: 0.12469100952148
DEBUG:SCRIPT: 0.1470890045166
DEBUG:SCRIPT: 0.10605406761169
DEBUG:SCRIPT: 0.14828491210938
DEBUG:SCRIPT: 0.12502789497375
DEBUG:SCRIPT: 0.13457012176514
DEBUG:SCRIPT: 0.1678740978241
DEBUG:SCRIPT: 0.16359305381775
DEBUG:SCRIPT: 0.19521594047546
DEBUG:SCRIPT: 0.17510104179382

#2

@Andreas_Tadic do you know what’s going on here?

#3

I’ve created an issue DEF-2661. We will look into this asap!

4 Likes
#4

Thanks guys. I’ve created a workaround but of course it would be in the future nice to use collections instead as composition objects.

1 Like
#5

I believe this is related to Collection Factory is leaking references (DEF-2596)
I get the same behavior.

2 Likes
#6

It seems all the time is consumed by handling reverse hashes. The codepath for doing this only applies to collectionfactory.create. I will investigate further on this, but for now, could you try this in release mode? You should not notice this behaviour since reverse hashing is disabled.

4 Likes
#7

Investigation shows this is down to handling reverse hashes, which is only done in debug mode.
Unfortunately, there is currently a problem with bundling the engine in release mode, see this post: PSA: Wrong engine version when bundling (SOLVED)

As stated above, a ticket is created for improving the reverse hashing performance.

#8

@a0ghosh This specific case (reverse hashes) is not related. Thanks for the input!

#9

How about making an option in project file, to opt out of reverse hashes in debug builds?

#10

Yes, we did discuss this as an alternative but want to do the planned optimisation in any case, as it’s needed.
We discussed having an option where it’s disabled by default, but I guess what you’re suggesting is a little less intrusive.
An option to disable this is very easy to implement, will discuss this again internally.

4 Likes