[Gc] RE: GC_gcollect and memory usage increase
Boehm, Hans
hans.boehm at hp.com
Fri Nov 17 17:09:56 PST 2006
Repeated memory growth like this may occur if a lot of the heap is
"blacklisted" because the collector saw what appeared to be pointers
into the newly allocated heap sections, and is trying to find a way to
allocate around such known bogus pointers. But based on the logs you
attached, things go fairly badly wrong well before that.
Was the collector built completely according to one of the recipes in
README.win32 for the multithreaded collector? If so, I would set a
breakpoint at the "Marking for collection" printf in GC_stopped_mark in
alloc.c, and check whether GC_gc_no is really decreasing between
messages, or whether the two messages are coming from different copies
of the collector that were linked in by mistake somehow. If GC_gc_no is
really decreasing, a watchpoint on it should be informative.
Hans
> -----Original Message-----
> From: Simon Tsai [mailto:mtsai at adobe.com]
> Sent: Friday, November 17, 2006 10:05 AM
> To: Boehm, Hans
> Cc: gc at napali.hpl.hp.com; gc at napali.hpl.hp.com
> Subject: GC_gcollect and memory usage increase
>
>
>
> My program is a muti-threaded server. It has more than 20
> threads running. Every time when my program call
> GC_gcollect(), I saw memory usage increase. After program
> allocate more than 200 Mbytes memory, each time GC_gcollect()
> get called, the memory usage start to jump.
> Eventually, my system runs out of memory. Does anyone see
> this problem?
> Any ways to prevent this happen?
>
> From gc.log:
>
> Immediately reclaimed -149556 bytes in heap of size 1099886592 bytes
> 580907008 (atomic) + 31759328 (composite) collectable bytes
> in use Finalize + initiate sweep took 0 + 688 msecs Complete
> collection took 12937 msecs Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes
>
> Why it keeps allocating 16 Mbytes memory, even my program did
> not request so much memory? Is this a bug?
> Why collection took 12937 msecs? It's a long time.
>
> Thanks,
>
>
> Simon
>
>
> =========================== gc.log ==========
>
> --> Marking for collection 7 after 214900 allocd bytes + 0
> wasted bytes
> Collection 6 reclaimed 0 bytes ---> heapsize = 1433600 bytes
> World-stopped marking took 1203 msecs Bytes recovered before
> sweep - f.l. count = -20164 Immediately reclaimed -20164
> bytes in heap of size 1433600 bytes 0 (atomic) + 118052
> (composite) collectable bytes in use Finalize + initiate
> sweep took 0 + 0 msecs Complete collection took 1719 msecs
> interior pointers
> --> Marking for collection 5 after 219478292 allocd bytes + 28187368
> wasted bytes
> Found new system malloc AllocationBase at 0x6ff0000 GC
> Warning: Thread stack pointer 0x5effe60 out of range, pushing
> everything Collection 4 reclaimed 328 bytes ---> heapsize =
> 227471360 bytes World-stopped marking took 7594 msecs Bytes
> recovered before sweep - f.l. count = -132976 Immediately
> reclaimed -132976 bytes in heap of size 227471360 bytes 0
> (atomic) + 17152084 (composite) collectable bytes in use
> Finalize + initiate sweep took 0 + 15 msecs Complete
> collection took 10109 msecs Increasing heap size by 16777216
> after 1594276 allocated bytes Increasing heap size by
> 16777216 after 1594276 allocated bytes Increasing heap size
> by 16777216 after 1775784 allocated bytes Increasing heap
> size by 16777216 after 1775784 allocated bytes Increasing
> heap size by 16777216 after 1775784 allocated bytes
> Increasing heap size by 16777216 after 2001608 allocated
> bytes Increasing heap size by 16777216 after 2001608
> allocated bytes Increasing heap size by 16777216 after
> 2049756 allocated bytes Increasing heap size by 16777216
> after 2049756 allocated bytes Increasing heap size by
> 16777216 after 15754676 allocated bytes Increasing heap size
> by 16777216 after 34413680 allocated bytes Increasing heap
> size by 16777216 after 52047912 allocated bytes Increasing
> heap size by 16777216 after 69681988 allocated bytes
> Increasing heap size by 16777216 after 86951164 allocated
> bytes Increasing heap size by 16777216 after 104327052
> allocated bytes Increasing heap size by 16777216 after
> 121389896 allocated bytes Initiating full world-stop
> collection 6 after 122212480 allocd bytes
> 151089152 bytes in heap blacklisted for interior pointers
> --> Marking for collection 6 after 122212480 allocd bytes + 145697160
> wasted bytes
> GC Warning: Thread stack pointer 0x5effe60 out of range,
> pushing everything Collection 5 reclaimed 709040 bytes --->
> heapsize = 495906816 bytes World-stopped marking took 6313
> msecs Bytes recovered before sweep - f.l. count = -162576
> Immediately reclaimed -162576 bytes in heap of size 495906816
> bytes 132382720 (atomic) + 26088876 (composite) collectable
> bytes in use Finalize + initiate sweep took 0 + 15 msecs
> Complete collection took 6562 msecs Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 935676 allocated bytes Increasing heap size by
> 16777216 after 20956028 allocated bytes Increasing heap size
> by 16777216 after 39119576 allocated bytes Increasing heap
> size by 16777216 after 57230224 allocated bytes Initiating
> full world-stop collection 7 after 64250476 allocd bytes
> 238878720 bytes in heap blacklisted for interior pointers
> --> Marking for collection 7 after 64250476 allocd bytes + 224500120
> wasted bytes
> Found new system malloc AllocationBase at 0x7c50000 GC
> Warning: Thread stack pointer 0x5effe60 out of range, pushing
> everything Collection 6 reclaimed 512912 bytes ---> heapsize
> = 764342272 bytes World-stopped marking took 20219 msecs
> Bytes recovered before sweep - f.l. count = -191728
> Immediately reclaimed -191728 bytes in heap of size 764342272
> bytes 352849920 (atomic) + 29610156 (composite) collectable
> bytes in use Finalize + initiate sweep took 0 + 1594 msecs
> Complete collection took 23297 msecs Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 68380 allocated bytes Increasing heap size by
> 16777216 after 288544 allocated bytes Increasing heap size by
> 16777216 after 288544 allocated bytes Increasing heap size by
> 16777216 after 311252 allocated bytes Increasing heap size by
> 16777216 after 311252 allocated bytes Increasing heap size by
> 16777216 after 311252 allocated bytes Increasing heap size by
> 16777216 after 311252 allocated bytes Increasing heap size by
> 16777216 after 311252 allocated bytes Increasing heap size by
> 16777216 after 311252 allocated bytes Increasing heap size by
> 16777216 after 9812544 allocated bytes Increasing heap size
> by 16777216 after 27763888 allocated bytes Increasing heap
> size by 16777216 after 45117616 allocated bytes Initiating
> full world-stop collection 8 after 48860960 allocd bytes
> 307335168 bytes in heap blacklisted for interior pointers
> --> Marking for collection 8 after 48860960 allocd bytes + 231524464
> wasted bytes
> Found new system malloc AllocationBase at 0x6100000 GC
> Warning: Thread stack pointer 0x5effe60 out of range, pushing
> everything Collection 7 reclaimed 517728 bytes ---> heapsize
> = 1099886592 bytes World-stopped marking took 8281 msecs
> Bytes recovered before sweep - f.l. count = -149556
> Immediately reclaimed -149556 bytes in heap of size 1099886592 bytes
> 580907008 (atomic) + 31759328 (composite) collectable bytes
> in use Finalize + initiate sweep took 0 + 688 msecs Complete
> collection took 12937 msecs Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Increasing heap size by 16777216
> after 124532 allocated bytes Initiating full world-stop
> collection 9 after 4770548 allocd bytes
> 403144704 bytes in heap blacklisted for interior pointers
> --> Marking for collection 9 after 4770548 allocd bytes + 75780 wasted
> bytes
>
More information about the Gc
mailing list