[racket] debugging memory allocation

From: David Vanderson (david.vanderson at gmail.com)
Date: Thu Nov 6 22:39:38 EST 2014

I'm having a UI problem in my game where major GCs cause noticeable, 
frequent pauses (every 5-15 seconds).  Jay's advice was to control 
allocation.  Minor GCs are no problem, and I'm okay with infrequent 
major GCs.

Problem is I don't know how to go about tracking this down, and need 
advice.  So far, all I know to do is run tests like this:
$ racket -W debug test-refresh.rkt 2>&1 | grep "^GC"

...wait until I see a stable pattern:
GC: 0:MAJ @ 137,893K(+-15,317K)[+6,816K]; free 76,189K(-76,189K) 142ms @ 
7259
GC: 0:MAJ @ 94,536K(+28,039K)[+6,816K]; free 32,910K(-49,278K) 156ms @ 11879
GC: 0:min @ 94,457K(+44,486K)[+6,816K]; free 23,981K(-23,981K) 12ms @ 16275
GC: 0:min @ 103,306K(+35,637K)[+6,816K]; free 23,929K(-23,929K) 9ms @ 20731
GC: 0:min @ 112,144K(+26,799K)[+6,816K]; free 23,949K(-23,949K) 11ms @ 25093
GC: 0:min @ 121,026K(+17,917K)[+6,816K]; free 24,004K(-24,004K) 12ms @ 29235
GC: 0:min @ 129,853K(+9,090K)[+6,816K]; free 24,001K(-24,001K) 11ms @ 33361
GC: 0:min @ 138,683K(+260K)[+6,816K]; free 23,990K(-23,990K) 12ms @ 37540
GC: 0:min @ 147,524K(+-8,580K)[+6,816K]; free 24,062K(-24,062K) 10ms @ 41429
GC: 0:MAJ @ 156,293K(+-17,349K)[+6,816K]; free 94,638K(-88,638K) 139ms @ 
45517
GC: 0:MAJ @ 94,486K(+38,457K)[+6,816K]; free 33,231K(-14,911K) 164ms @ 50118

I couldn't find info in the docs about how to interpret these numbers 
(did I miss it?).  I'm taking the first number as a memory growth, and 
the last number as milliseconds, so between major GCs in this run, I'm 
generating about (147,524K - 94,457K) / (41429ms - 16275ms) = 2.1 K / ms 
or about 2.1 M / s.

How should I go about figuring out how much garbage I'm generating? Is 
there a way to trace where it's coming from?

Thanks,
Dave

Posted on the users mailing list.