something wrong with the IOS gc?

Monkey Targets Forums/iOS/something wrong with the IOS gc?

dmaz	(Posted 2011) [#1]

here is a quick test I used to confirm my search for a slow-down I was having. the following code pre-allocates 6000 "Ball" object with 10 "Fill" objects. *After* allocating the objects (not touching the screen or mousedown) brings my iPhone 4 to down to ~5 fps. while running on mac and pc in either GLFW or HTML5 stays 60fps

instruments identified all the processing going to gc_mark and gc_mark_q for the Ball and Fill objects. should the GC be doing this every frame?

Import mojo
Import monkey.list


Function Main()
	New MyApp
End

Class MyApp Extends App
	Field list:List<Ball> = New List<Ball>
	
	Method OnCreate()
		SetUpdateRate 60
		Ball.PreAlloc(6000)
	End
	
	Method OnUpdate()
		Ball.UpdateAll	
		If TouchDown(0)
			For Local i:Int = 0 Until 10
				Ball.Alloc().Init(Rnd(DeviceWidth),0)
			Next
		End
	End
	
	Method OnRender()
		Cls 0,0,0
		DrawText Ball.count,0,DeviceHeight()-40
		DrawText FPS,0,DeviceHeight()-20
		Ball.RenderAll
	End
	
	Method FPS:Int()
		frameCount+=1
		If frameCount >= 30
			frameRate = Int(1000.0 / (Float(Millisecs - frameCountStartTime)/30.0))
			frameCount = 0
			frameCountStartTime = Millisecs
		End
		Return frameRate
	End
	
	Private
	Field frameRate:Int
	Field frameCount:Int
	Field frameCountStartTime:Int
End


Class Ball	
	' --------------------------------------------------------------------------------------------------
	' P O O L
	Global pool			:Ball
	Field succ			:Ball	' used for the pool

	Function PreAlloc( number:Int )
		For Local i:Int = 0 Until number
			Local obj := New Ball
			obj.succ = pool
			pool = obj
		Next
	End
	
	Function Alloc:Ball()
		Local obj:Ball
		If pool
			obj = pool
			pool = obj.succ
		Else
			Print "new ball"
			obj = New Ball
		Endif
		
		Return obj
	End

	Method Remove()
		succ = pool
		pool = Self
	End

	' --------------------------------------------------------------------------------------------------
	' C L A S S
	Global list:List<Ball> = New List<Ball>
	Global count:Int
	
	Field x:Int
	Field y:Int
	Field n:list.Node<Ball>
	Field f:Fill[10]
	
	Method New()
		For Local i:Int = 0 Until 10
			f[i] = New Fill
		End
	End
	
	Method Init:Ball( x:Float, y:Float )
		Self.x = x
		Self.y = y
		Self.n = list.AddLast(Self)
		count += 1
		Return Self
	End
	
	Function UpdateAll()
		For Local b:Ball = Eachin list
			b.OnUpdate
		Next
	End
	
	Function RenderAll()
		For Local b:Ball = Eachin list
			b.OnRender
		Next
	End
	
	Method OnUpdate()
		y += 1
		If y > DeviceHeight
			count -= 1
			n.Remove
			Remove
		End
	End
	
	Method OnRender()
		DrawCircle x,y,10		
	End
		
End

Class Fill
	Field value
	Method New()
		value = 0
	End
End

therevills

(Posted 2011) [#2]

Only thing I can see in the code which might slow it down, is the EachIn statements in Ball.UpdateAll and Ball.RenderAll... every time you call EachIn you create a new Enumerator.

Also 6000 is alot of objects for a mobile device too...

dmaz	(Posted 2011) [#3]

thanks, but no it's not that... creating 2 objects per frame isn't going to slow down any phone. every frame your phone creates objects whether you like it or not... you need to keep it to a minimum though so you should always pool objects as much as possible.

actually, the example above is 60,000 as each ball has 10 fill objects. this was just a test to illustrate what happens when all I did was just allocate the objects and not process them at all. I did this because it seemed (according to Instruments) Mark's GC routines were taking more processing than the actual drawing routines like DrawOval...

it seems that Mark's IOS GC's performance is not linear? on my iPhone4 it takes about 1000 Balls for for the gc routines to pass DrawOval in processing time.

marksibly

(Posted 2011) [#4]

Hi,

The GC must visit all objects to work out which ones are dead, so it's visiting 60,000 objects per update/render.

The gc could be delayed until 'N' bytes are allocated, but then you'd get big 'lumps' when gc kicked in - all part of the fun of trying to make gc work in a realtime environment. And 60,000 objs is a lot for a mobile device to handle.

In this case, preallocating objects is not helping and you're probably better off using 'new' (if this is what the preallocation is trying to 'solve').

Is slow new even a problem on c++ targets? I know it is on xna/android, but the c++ gc was written under the assumption people wouldn't need to use preallocation, so 'new' was a good indication of 'live' objects.

[edit]
Another thing - make sure to build 'release' version! This is kind of non-obvious on xcode4.2, but significantly speeds up the GC - your code above runs at 60fps in release mode on my iPad (just). Also note this issue has kind of created a situation where you should avoid 'new' on xna/android, but avoid pre-allocation on c++ targets...thinking...!
[/edit]

dmaz	(Posted 2011) [#5]

yeah, 60,000 is A LOT but that was just to emphasize the issue for me by bringing down the fps while doing seemly nothing at all. and maybe, it's not really as much as we may think. for instance, my scenegraph nodes have a
position vector object,
world position vector
size object,
handle vector
scale vector
color object
background color object
a float array for the current matrix
and even angle and
blend objects since all of these can be animated.

so that's 10 objects for every node, extended nodes add more. so when I was started to profile I found that the GC was the biggest cpu user even for a just hundred objects.

yes, new is slow on the iphone and quite measure-able... w whole lot slower than desktops. even on desktops I'd pool things like particle engines though.

does the GC have to visit each object every frame? what about only processing a third or something each frame?

better yet, how about a command that leaves an object instance hidden from GC processing? as there are always instances that you want to keep for the whole game or you know exactly where they should be destroyed. like at the end of a level. recycling objects on mobile devices is very important, pooling as well.... I agree that you don't have to pool all objects but if you are going to create more than a few objects in a frame... those should then be pooled or you'll get a 'lump'.

my current testing on an iphone 4 shows that preallocation is important on that device for things like particle engines.... but the GC is taking 20-30% of my processing every loop on the iphone 4

when I was using cocos2d on my iphone 3, I pretty much had to pool everything. I haven't yet profiled this issue on that phone yet but I'll do that maybe tonight.

siread

(Posted 2011) [#6]

60,000 objects may be a lot for an action game but for something like a football manager game or an RPG I would say that it's not unusual at all, particularly since we only have SaveState for storing data and cannot whack it in temporary files.

dmaz	(Posted 2011) [#7]

I've modified the code.... it currently doesn't preallocate anything so I can profile the build up of objects. it does recycle though so you would have to do a new run to get back to 0. touch adds objects and second touch removes(but recycles)

these last test were for an iPhone 3g running 4.2.1 in release and profiled using xcode 4.2. I had to set the update rate to 30 to display a decent number of rects (500, is stable). I expected this as I ran all my old cocos2d stuff at 30 as well.

I really think adding something like a "alloc" and "destroy/delete" to use -only- when the programmer doesn't want the gc managing the object would be the best of both worlds!

I ended up here with a total of ~25% cpu going to the GC.

Running Time	Self		Symbol Name
3152.0ms   19.1%	3152.0	 	gc_mark(gc_object*)
2283.0ms   13.8%	2283.0	 	mach_msg_trap
843.0ms    5.1%	843.0	 	gc_mark_q(gc_object*)
407.0ms    2.4%	407.0	 	0x3023a96c
365.0ms    2.2%	365.0	 	bb_list_Enumerator::m_NextObject()
358.0ms    2.1%	358.0	 	Reinterleaver::ConvertBufferList(unsigned long, CABufferList const*, CABufferList*)
355.0ms    2.1%	355.0	 	bb_iosgctest_Ball::m_OnUpdate()
301.0ms    1.8%	301.0	 	gxtkGraphics::DrawRect(float, float, float, float)
255.0ms    1.5%	255.0	 	Int32ToInt16_ARM
220.0ms    1.3%	220.0	 	memcpy
210.0ms    1.2%	210.0	 	Array<bb_iosgctest_Fill*>::Rep::mark()
170.0ms    1.0%	170.0	 	bb_iosgctest_Ball::g_RenderAll()
167.0ms    1.0%	167.0	 	objc_msgSend
153.0ms    0.9%	153.0	 	bb_iosgctest_Ball::m_OnRender()
153.0ms    0.9%	153.0	 	mk_timer_arm
145.0ms    0.8%	145.0	 	bb_iosgctest_Ball::g_UpdateAll()
138.0ms    0.8%	138.0	 	pthread_setspecific
137.0ms    0.8%	137.0	 	bb_graphics_ValidateMatrix()
131.0ms    0.7%	131.0	 	gc_collect()
120.0ms    0.7%	120.0	 	bb_iosgctest_Fill::mark()
118.0ms    0.7%	118.0	 	__CFRunLoopDoObservers
112.0ms    0.6%	112.0	 	__bzero
104.0ms    0.6%	104.0	 	pthread_once
100.0ms    0.6%	100.0	 	std::vector<gc_object*, std::allocator<gc_object*> >::push_back(gc_object* const&)
96.0ms    0.5%	96.0	 	pthread_mutex_lock
86.0ms    0.5%	86.0	 	OSSpinLockLock
84.0ms    0.5%	84.0	 	io_connect_method
78.0ms    0.4%	78.0	 	pthread_mutex_unlock
77.0ms    0.4%	77.0	 	mach_absolute_time
72.0ms    0.4%	72.0	 	_CFArrayReplaceValues
69.0ms    0.4%	69.0	 	AUBase::DoRender(unsigned long&, AudioTimeStamp const&, unsigned long, unsigned long, AudioBufferList&)
68.0ms    0.4%	68.0	 	tiny_malloc_from_free_list
68.0ms    0.4%	68.0	 	bb_list_Enumerator::m_HasNext()
68.0ms    0.4%	68.0	 	__CFRunLoopDoTimer
68.0ms    0.4%	68.0	 	bb_iosgctest_Ball::mark()
68.0ms    0.4%	68.0	 	__CFRunLoopRun
64.0ms    0.3%	64.0	 	0x3023a6fc
59.0ms    0.3%	59.0	 	CFArrayGetValueAtIndex
58.0ms    0.3%	58.0	 	szone_malloc_should_clear
57.0ms    0.3%	57.0	 	___CFBasicHashFindBucket_Linear
56.0ms    0.3%	56.0	 	__vfprintf
55.0ms    0.3%	55.0	 	gxtkApp::InvokeOnUpdate()
55.0ms    0.3%	55.0	 	_Unwind_SjLj_Register
50.0ms    0.3%	50.0	 	bb_list_Node::mark()
50.0ms    0.3%	50.0	 	szone_free_definite_size
49.0ms    0.2%	49.0	 	AURemoteIO::PerformIO(unsigned int, unsigned int, XAudioTimeStamp const&, XAudioTimeStamp const&, int&)
49.0ms    0.2%	49.0	 	CFArrayGetCount

profile detail

Running Time	Self		Symbol Name
3152.0ms   19.1%	3152.0	 	gc_mark(gc_object*)
2731.0ms   16.5%	0.0	 	 Array<bb_iosgctest_Fill*>::Rep::mark()
240.0ms    1.4%	0.0	 	 bb_iosgctest_Ball::mark()
132.0ms    0.8%	0.0	 	 Array<bb_graphics_Frame*>::Rep::mark()
36.0ms    0.2%	0.0	 	 gc_mark(gc_object*)
34.0ms    0.2%	0.0	 	  bb_iosgctest_Ball::mark()
2.0ms    0.0%	0.0	 	  bb_graphics_Image::mark()
6.0ms    0.0%	0.0	 	 gc_collect()
5.0ms    0.0%	0.0	 	 bb_graphics_Image::mark()
2.0ms    0.0%	0.0	 	 gc_mark()
2283.0ms   13.8%	2283.0	 	mach_msg_trap
843.0ms    5.1%	843.0	 	gc_mark_q(gc_object*)
664.0ms    4.0%	0.0	 	 bb_list_Node::mark()
155.0ms    0.9%	0.0	 	 bb_iosgctest_Ball::mark()
20.0ms    0.1%	0.0	 	 gc_collect()
3.0ms    0.0%	0.0	 	 bb_graphics_Image::mark()
1.0ms    0.0%	0.0	 	 bb_app_AppDevice::mark()
407.0ms    2.4%	407.0	 	0x3023a96c
365.0ms    2.2%	365.0	 	bb_list_Enumerator::m_NextObject()
358.0ms    2.1%	358.0	 	Reinterleaver::ConvertBufferList(unsigned long, CABufferList const*, CABufferList*)
355.0ms    2.1%	355.0	 	bb_iosgctest_Ball::m_OnUpdate()
301.0ms    1.8%	301.0	 	gxtkGraphics::DrawRect(float, float, float, float)

test code

Import mojo
Import monkey.list


Function Main()
	New MyApp
End

Class MyApp Extends App
	Field list:List<Ball> = New List<Ball>
	
	Method OnCreate()
		SetUpdateRate 30
'		Ball.PreAlloc(1000)
	End
	
	Method OnUpdate()
		Ball.UpdateAll
		If TouchDown(1) Or MouseHit(1)
			Ball.RemoveAll
		Elseif TouchDown(0)
			For Local i:Int = 0 Until 10
				Ball.Alloc().Init(Rnd(DeviceWidth),0)
			Next
		End
	End
	
	Method OnRender()
		Cls 0,0,0
		Ball.RenderAll
		DrawText Ball.count,0,DeviceHeight()-40
		DrawText FPS,0,DeviceHeight()-20
	End
	
	Method FPS:Int()
		frameCount+=1
		If frameCount >= 30
			frameRate = Int(1000.0 / (Float(Millisecs - frameCountStartTime)/30.0))
			frameCount = 0
			frameCountStartTime = Millisecs
		End
		Return frameRate
	End
	
	Private
	Field frameRate:Int
	Field frameCount:Int
	Field frameCountStartTime:Int
End


Class Ball	
	' --------------------------------------------------------------------------------------------------
	' P O O L
	Global pool			:Ball
	Field succ			:Ball	' used for the pool

	Function PreAlloc( number:Int )
		For Local i:Int = 0 Until number
			Local obj := New Ball
			obj.succ = pool
			pool = obj
		Next
	End
	
	Function Alloc:Ball()
		Local obj:Ball
		If pool
			obj = pool
			pool = obj.succ
		Else
			obj = New Ball
		Endif
		
		Return obj
	End

	Method Remove()
		succ = pool
		pool = Self
	End

	' --------------------------------------------------------------------------------------------------
	' C L A S S
	Global list:List<Ball> = New List<Ball>
	Global count:Int
	
	Field x:Float
	Field y:Float
	Field ax:Float
	Field ay:Float
	Field n:list.Node<Ball>
	Field f:Fill[10]
	
	Method New()
		For Local i:Int = 0 Until 10
			f[i] = New Fill
		End
	End
	
	Method Init:Ball( x:Float, y:Float )
		Self.x = x
		Self.y = y
		Self.ax = Rnd(4)-2
		Self.ay = Rnd(4)-2
		Self.n = list.AddLast(Self)
		count += 1
		Return Self
	End
	
	Function RemoveAll()
		For Local b:Ball = Eachin list
			b.n.Remove
			b.Remove
		Next
		count = 0
	End
	
	Function UpdateAll()
		For Local b:Ball = Eachin list
			b.OnUpdate
		Next
	End
	
	Function RenderAll()
		For Local b:Ball = Eachin list
			b.OnRender
		Next
	End
	
	Method OnUpdate()
		y += ay
		x += ax
		If y < 0 Or y > DeviceHeight Then ay = -ay
		If x < 0 Or x > DeviceWidth Then ax = -ax
	End
	
	Method OnRender()
		DrawRect x,y,16,16		
	End
		
End

Class Fill
	Field value
	Method New()
		value = 0
	End
End

dmaz	(Posted 2011) [#8]

in other words... I think the GC should still know about them even with alloc so it can destroy them as application close if needed. it just wouldn't mark... but obviously would collect with destroy. that would be awesome and a very good addition to a language for games.

dmaz	(Posted 2011) [#9]

Mark, I missed your [edit] above... under xcode 4.2 the 'Profile' setting does run in release (I will confirm when I get home) are you running on an iPad 1 or 2? I didn't test on mine but I'll do that as well.

that said, I think the last set of tests I did were more conclusive and they were not pre-allocating lots of objects.

dmaz	(Posted 2011) [#10]

Another thing - make sure to build 'release' version! This is kind of non-obvious on xcode4.2, but significantly speeds up the GC - your code above runs at 60fps in release mode on my iPad (just). Also note this issue has kind of created a situation where you should avoid 'new' on xna/android, but avoid pre-allocation on c++ targets...thinking...!

yeah, the original run from my first post was xcodes "run" which meant "debug" as you thought, sorry 'bout that! the tests 2 posts above were all done in release though under profile and a "fixed" (release) run.

just for completeness, redoing the original code under release brings:
ipad 1 = 60fps
iphone 4 = choppy 35-50fps
iphone 3g = 4 fps

i'm thinking about ways to minimize the number of objects I want to use... it's crossed my mind to re-write my nodes to use plain datatypes but that really defeats the purpose of objects in the first place and I can't bring my self to do it.

I just want to reiterate that the GC still takes up the bulk of the cpu even at normal/low object numbers on all three of my devices. so I think this is still a problem. but I also don't want to lose the GC. As I mentioned above (not knowing how difficult implementation would be), allowing some objects not to be visited but only when the programmer specifies through an alloc/delete should be a great solution I think.