What do GC_FOR_MALLOC, GC_EXPLICIT, and other GC_*

Question

If you see the Android logs, you may see a lot of those things.

What do they mean, knowing those may help us doing better memory allocations.

Example:

 28470               dalvikvm  D  GC_FOR_MALLOC freed 665 objects / 239992 bytes in 71ms
 28470               dalvikvm  D  GC_FOR_MALLOC freed 673 objects / 240288 bytes in 87ms
 21940               dalvikvm  D  GC_EXPLICIT freed 4802 objects / 185320 bytes in 78ms
 28470               dalvikvm  D  GC_FOR_MALLOC freed 666 objects / 240536 bytes in 63ms

Answer 1

Another place where the Dalvik garbage collector messages are explained is in this video: Google I/O 2011: Memory management for Android Apps

At about 14 minutes into the presentation, he breaks down the message format. (BTW, that video has really good info on debugging memory leaks)

Roughly speaking, the format is [Reason] [Amount Freed], [Heap Statistics], [External Memory Statistics], [Pause Time]

Reason

Robert/yuku already gave info on the meaning of these.

Amount Freed

E.g. freed 2125K

Self explanatory

Heap Statistics

E.g. 47% free 6214K/11719K

These numbers reflect conditions after the GC ran. The "47% free" and 6214K reflect the current heap usage. The 11719K represents the total heap size. From what I can tell, the heap can grow/shrink, so you will not necessarily have an OutOfMemoryError if you hit this limit.

External Memory Statistics

E.g external 7142K/8400K

Note: This might only exist in pre-Honeycomb versions of Android (pre 3.0).

Before Honeycomb, bitmaps are allocated external to your VM (e.g. Bitmap.createBitmap() allocates the bitmap externally and only allocates a few dozen bytes on your local heap). Other examples of external allocations are for java.nio.ByteBuffers.

Pause Time

If it's a concurrent GC event, there will be two times listed. One is for a pause before the GC, one is for a pause when the GC is mostly done. E.g. paused 3ms+5ms

For non-concurrent GC events, there is only one pause time and it's typically much bigger. E.g. paused 87ms

Answer 2

I also found this in the Android sources, dalvik/vm/alloc/Heap.h. May this be useful.

typedef enum {
    /* Not enough space for an "ordinary" Object to be allocated. */
    GC_FOR_MALLOC,
    /* Automatic GC triggered by exceeding a heap occupancy threshold. */
    GC_CONCURRENT,
    /* Explicit GC via Runtime.gc(), VMRuntime.gc(), or SIGUSR1. */
    GC_EXPLICIT,
    /* GC to try to reduce heap footprint to allow more non-GC'ed memory. */
    GC_EXTERNAL_ALLOC,
    /* GC to dump heap contents to a file, only used under WITH_HPROF */
    GC_HPROF_DUMP_HEAP
} GcReason;

Answer 3

GC_FOR_MALLOC means that the GC was triggered because there wasn't enough memory left on the heap to perform an allocation. Might be triggered when new objects are being created.

GC_EXPLICIT means that the garbage collector has been explicitly asked to collect, instead of being triggered by high water marks in the heap. Happens all over the place, but most likely when a thread is being killed or when a binder communication is taken down.

There are a few others as well:

GC_CONCURRENT Triggered when the heap has reached a certain amount of objects to collect.

GC_EXTERNAL_ALLOC means that the the VM is trying to reduce the amount of memory used for collectable objects, to make room for more non-collectable.

Update: There has been a name-change of the first event in later versions of Android. It's now called "GC_FOR_ALLOC". There is also a new event available, although very rare in modern phones: GC_BEFORE_OOM means that the system is running really low on memory, and that there is a final GC performed, in order to avoid calling the low memory killer.