[erlang-questions] Extraordinarily long garbage collection with R12B-2

[David Lutz]

I am still pretty much an erlang newbie, so hopefully I am missing  
something obvious.

We have an program that was running OK with R11B-4, but now is  
experiencing incredibly long garbage collection times under load with  
R12B-2.  The application is serving network requests, many clients  
connecting only for a short period, request/response style.  We have  
erlang:system_monitor/2 set up to deliver messages if GC takes more  
than 1000ms.  With R11B-4 we almost never saw this.  With R12B-2 it  
happens fairly regularly and the timeouts are really long, most of the  
reports are for timeout of 4294967.  Occasionally a slightly smaller  
timeout will be reported, but always well over 4000000.  The long GC  
happens in both our long running gen_server processes and our  
ephemeral worker processes.  Obviously our clients experience timeouts  
and other connection errors while this long GC is happening.

Below is small clip from our log file showing the long GC reports.   
Has anybody seen this issue before?  Why would R12B-2 behave so much  
different that R11B-4 in this respect?  What steps can I try to  
pinpoint the issue?

Thanks,
D.L.

=INFO REPORT==== 2008-06-29 02:02:41 UTC ===
Long GC in <0.13094.0>: [{timeout,4294967},
                          {old_heap_block_size,610},
                          {heap_block_size,987},
                          {mbuf_size,0},
                          {stack_size,10},
                          {old_heap_size,173},
                          {heap_size,425}]
ProcessRegisteredName: []

=INFO REPORT==== 2008-06-29 02:02:43 UTC ===
Long GC in <0.59.0>: [{timeout,4295024},
                       {old_heap_block_size,377},
                       {heap_block_size,610},
                       {mbuf_size,0},
                       {stack_size,26},
                       {old_heap_size,118},
                       {heap_size,7}]
ProcessRegisteredName: {registered_name,XXX}

=INFO REPORT==== 2008-06-29 02:02:49 UTC ===
Long GC in <0.18816.0>: [{timeout,4294967},
                          {old_heap_block_size,377},
                          {heap_block_size,987},
                          {mbuf_size,0},
                          {stack_size,14},
                          {old_heap_size,33},
                          {heap_size,476}]
ProcessRegisteredName: []

=INFO REPORT==== 2008-06-29 02:02:52 UTC ===
Long GC in <0.21233.0>: [{timeout,4294967},
                          {old_heap_block_size,1597},
                          {heap_block_size,987},
                          {mbuf_size,0},
                          {stack_size,31},
                          {old_heap_size,28},
                          {heap_size,878}]
ProcessRegisteredName: []

=INFO REPORT==== 2008-06-29 02:02:53 UTC ===
Long GC in <0.22024.0>: [{timeout,4294967},
                          {old_heap_block_size,610},
                          {heap_block_size,610},
                          {mbuf_size,0},
                          {stack_size,32},
                          {old_heap_size,352},
                          {heap_size,276}]
ProcessRegisteredName: []