[racket-dev] gc much slower in DrR?

Any difference with 9dd83008a6 (just pushed)?

At Thu, 11 Oct 2012 15:43:49 -0700, John Clements wrote:
> I'm trying to run signal-based audio programs, and I'm finding that DrR is 
> using well over 10x the time to perform the same GC's as command-line racket. 
> Let me be more specific: I'm running a program that does a little filtering to 
> combine a couple of oscillators, using big-bang. Running this program in DrR, I 
> see GC logs that look like this:
> 
> GC: 0:min @ 711,798K(+89,158K)[+46,912K]; free 32,654K(-32,654K) 66ms @ 2058318
> GC: 0:min @ 712,070K(+88,886K)[+46,912K]; free 32,667K(-32,667K) 69ms @ 2059160
> GC: 0:min @ 712,421K(+88,534K)[+46,916K]; free 32,724K(-32,724K) 71ms @ 2059963
> GC: 0:min @ 712,621K(+88,334K)[+46,916K]; free 32,698K(-32,698K) 68ms @ 2060857
> GC: 0:min @ 713,411K(+87,545K)[+46,916K]; free 33,103K(-33,103K) 80ms @ 2061605
> GC: 0:min @ 713,424K(+87,532K)[+46,916K]; free 32,815K(-32,815K) 78ms @ 2062341
> GC: 0:min @ 714,273K(+86,683K)[+46,916K]; free 33,363K(-33,363K) 75ms @ 2062872
> GC: 0:min @ 715,799K(+85,157K)[+46,916K]; free 30,988K(-30,988K) 104ms @ 2063857
> …
> 
> These GCs are happening about 17 times in every 30 seconds; given the amount 
> freed, this suggests that I'm generating about 18 Megabytes of trash per 
> second, which seems like a lot until you divide by the sample rate of 44.1KHz, 
> when it comes out to be 419 bytes of trash per sample generated, which seems 
> like it's in the right ballpark.
> 
> I tried running the same program on the command-line, with "racket -W debug 
> ./interesting-tones.rkt", and the GC traces looked like this:
> 
> GC: 0:min @ 124,249K(+26,774K)[+11,396K]; free 32,735K(-32,735K) 5ms @ 14101
> GC: 0:min @ 124,282K(+26,741K)[+11,396K]; free 32,737K(-32,737K) 5ms @ 14563
> GC: 0:min @ 124,341K(+26,682K)[+11,396K]; free 32,762K(-32,762K) 5ms @ 15032
> GC: 0:min @ 124,340K(+26,683K)[+11,396K]; free 32,724K(-49,108K) 7ms @ 15506
> GC: 0:min @ 124,383K(+43,024K)[+11,396K]; free 32,733K(-32,733K) 6ms @ 15967
> GC: 0:min @ 124,402K(+43,005K)[+11,396K]; free 32,708K(-32,708K) 6ms @ 16419
> GC: 0:min @ 124,461K(+42,946K)[+11,396K]; free 32,736K(-32,736K) 5ms @ 16864
> GC: 0:min @ 124,513K(+42,894K)[+11,396K]; free 32,743K(-32,743K) 10ms @ 17312
> GC: 0:min @ 124,563K(+42,844K)[+11,396K]; free 32,764K(-32,764K) 5ms @ 17767
> GC: 0:min @ 124,566K(+42,841K)[+11,396K]; free 32,739K(-32,739K) 6ms @ 18227
> GC: 0:min @ 124,595K(+42,812K)[+11,396K]; free 32,733K(-32,733K) 5ms @ 18681
> GC: 0:min @ 124,628K(+42,779K)[+11,440K]; free 32,673K(-32,673K) 9ms @ 19161
> ….
> 
> Note that it's collecting about the same amount of trash each time (about 
> 32Meg), but the gc pauses are only 5-10 ms, rather than 60-100. This means no 
> audible pauses, and it sounds quite nice, rather than extremely hiccupy.
> 
> I see that DrR's heap is much bigger: 713Meg vs 125Meg. Would this account for 
> the much longer GC times? I'm imagining that these are minor collections, that 
> don't affect much outside of the nursery (and I guess I'm assuming we have a 
> generational collector), so it seems like the bulky background shouldn't affect 
> the GC times, at least not by a factor of 10.  Is there something else going on?
> 
> John
> 
> 
> P.S.: I should admit that I think I could address this problem in DrR by 
> turning the buffer size up to, say, 200ms, but that's a really slow response 
> rate; if you're trying to play a keyboard, for instance, 200ms feels quite 
> sluggish.
> 
> P.P.S.: this version of DrR hasn't been updated in a month… I suppose I should 
> update, and perhaps something magical will happen :).
> 
> 
> ------------------------------------------------------------------------------
> [application/pkcs7-signature "smime.p7s"] [~/Desktop & open] [~/Temp & open]
> _________________________
>   Racket Developers list:
>   http://lists.racket-lang.org/dev