Java GC runs very often after minimal allocations
I'm writing a realtime game for an android, and so I would like to minimize garbage collection / collection as recommended in the androids Design for Performance tutorial.
I have a very simple game that doesn't use a lot of memory (and 2-3% of the heap according to the hprof heap dump), but my parallel gc runs like a clock every 7 seconds, always freeing about 1MB of memory. My game is completely paused and not doing anything interesting, and running allocation tracking for 5 seconds shows very little allocation. This is a complete dump of the allocation tracker after opening for a few seconds, which accounts for less than 1KB of allocations (basically just dalvik stuff and my lock / unlock method).
19 24 byte[] 5 dalvik.system.NativeStart run
18 12 java.lang.Integer 5 java.lang.Integer valueOf
17 24 org.apache.harmony.dalvik.ddmc.Chunk 5 org.apache.harmony.dalvik.ddmc.DdmServer dispatch
16 17 byte[] 5 android.ddm.DdmHandleHeap handleREAQ
15 24 org.apache.harmony.dalvik.ddmc.Chunk 5 android.ddm.DdmHandleHeap handleREAQ
14 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
13 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
12 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
11 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
10 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
9 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
8 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
7 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
6 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
5 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
4 28 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node 10 java.util.concurrent.locks.AbstractQueuedSynchronizer addWaiter
3 24 byte[] 5 dalvik.system.NativeStart run
2 12 java.lang.Integer 5 java.lang.Integer valueOf
1 24 org.apache.harmony.dalvik.ddmc.Chunk 5 org.apache.harmony.dalvik.ddmc.DdmServer dispatch
However, despite all this, I constantly see about 1 MB of collection every few seconds:
03-09 21:41:56.665: D/dalvikvm(4210): GC_CONCURRENT freed 934K, 58% free 3069K/7175K, external 2847K/3550K, paused 3ms+2ms
03-09 21:42:03.685: D/dalvikvm(4210): GC_CONCURRENT freed 937K, 58% free 3069K/7175K, external 2847K/3550K, paused 3ms+1ms
03-09 21:42:10.705: D/dalvikvm(4210): GC_CONCURRENT freed 937K, 58% free 3069K/7175K, external 2847K/3550K, paused 5ms+2ms
03-09 21:42:17.715: D/dalvikvm(4210): GC_CONCURRENT freed 934K, 58% free 3069K/7175K, external 2847K/3550K, paused 3ms+1ms
03-09 21:42:24.725: D/dalvikvm(4210): GC_CONCURRENT freed 934K, 58% free 3069K/7175K, external 2847K/3550K, paused 2ms+3ms
I know I am running out of time, although I would not want 10 milliseconds to be accidentally stolen from one of my frames if I can avoid it. My question is I don't see anything in the allocation tracker, just what can allocate so much memory in just a few seconds? I don't think this is something in the background of the phone, because as soon as I exit the game, I no longer see the GC (or very rarely).
My render thread is using GLSurfaceView which pretty much only works when paused, but I'm just stumped where my memory is going.
Any thoughts are appreciated.
source to share
Ok I found a leak. It turns out I was running the clone without the need for a floating point array about 50 times per frame, but what really threw me off was that it doesn't show up in the allocation tracker.
A bit more research showed me this thread which seems to assert that there is an android bug where array.clone () operations are not showing up in the distribution tracker.
Disappointed, it took me a long time to find it, but at least I'm only collecting 1KB per second right now.
source to share