[squeak-dev] >1 hour to garbage collect

Chris Muller ma.chris.m at gmail.com
Fri Nov 18 22:49:42 UTC 2016


I finally figured out what I thought was a bug in my own code was actually
just exposing something about Spur which I had never experienced before --
*incredibly* long time for it to garbage collect.

I kept thinking the image was locking up, but in fact it was just doing a
GC and does eventually come back.  But, clearly, something has GOT to be
wrong here...  Eliot?   Should GC take

I put in some debugging statements into source.squeak.org's start-up
initialization which give us essential VM information at each step, check
it out.

===========
*** First before doing anything, snapshot the VM parameters
2016-11-18T15:05:07.256516-06:00 Virtual Machine Parameters
2016-11-18T15:05:07.25729-06:00 --------------------------
2016-11-18T15:05:07.257693-06:00 #1 118,531,328 size of old space
2016-11-18T15:05:07.257781-06:00 #2 2,368,536 size of new space
2016-11-18T15:05:07.257838-06:00 #3 125,304,832 size of heap
2016-11-18T15:05:07.258414-06:00 #7 2 full GCs since startup
2016-11-18T15:05:07.258471-06:00 #8 330 total milliseconds in full GCs
since startup
2016-11-18T15:05:07.258521-06:00 #9 72 scavenging GCs since startup
2016-11-18T15:05:07.258588-06:00 #10 26 total milliseconds in scavenging
GCs since startup
2016-11-18T15:05:07.258639-06:00 #11 2,249 tenures of surving objects since
startup

*** Looks good, so load the SSRepository object and indexes from Magma
2016-11-18T15:05:07.258706-06:00 Loading SSRepository...
2016-11-18T15:07:54.675452-06:00 Loading Indexes...
2016-11-18T15:07:54.679669-06:00 Virtual Machine Parameters
2016-11-18T15:07:54.679771-06:00 --------------------------
2016-11-18T15:07:54.679842-06:00 #1 806,397,184 size of old space
2016-11-18T15:07:54.679909-06:00 #2 1,086,968 size of new space
2016-11-18T15:07:54.679985-06:00 #3 813,170,688 size of heap
2016-11-18T15:07:54.680058-06:00 #7 17 full GCs since startup
2016-11-18T15:07:54.680126-06:00 #8 6,699 total milliseconds in full GCs
since startup
2016-11-18T15:07:54.680191-06:00 #9 8,977 scavenging GCs since startup
2016-11-18T15:07:54.680255-06:00 #10 96,048 total milliseconds in
scavenging GCs since startup
2016-11-18T15:07:54.680319-06:00 #11 15,015,301 tenures of surving objects
since startup

*** 2 minutes since startup, so far so good, but now do a "Smalltalk
garbageCollect"...
2016-11-18T15:07:54.680384-06:00 Garbage collecting now...
2016-11-18T16:25:38.072284-06:00 *0:01:17:43.39 to GC after initialization.*
2016-11-18T16:25:38.075849-06:00 Virtual Machine Parameters
2016-11-18T16:25:38.075949-06:00 --------------------------
2016-11-18T16:25:38.076023-06:00 #1 705,733,888 size of old space
2016-11-18T16:25:38.076092-06:00 #2 694,752 size of new space
2016-11-18T16:25:38.076158-06:00 #3 712,507,392 size of heap
2016-11-18T16:25:38.076227-06:00 #7 18 full GCs since startup
2016-11-18T16:25:38.076297-06:00 #8 4,670,088 total milliseconds in full
GCs since startup
2016-11-18T16:25:38.076366-06:00 #9 8,977 scavenging GCs since startup
2016-11-18T16:25:38.076434-06:00 #10 96,048 total milliseconds in
scavenging GCs since startup
2016-11-18T16:25:38.076506-06:00 #11 15,015,301 tenures of surving objects
since startup
2016-11-18T16:25:44.141442-06:00 *** Checking integrity of the repository...
============

I *think* there is only one such of these super-long GC's, afterward it
returns to normal, short GC times.

So, I guess I will move forward with deploying my latest code which I
thought was locking the image, but apparently not.  But this super-long GC
is problematic in any case.  Eliot, is there any case for Spur to take so
long and report those numbers which I could avoid?  In years of using Spur,
I've never actually noticed this issue before...  I'm really puzzled.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squeakfoundation.org/pipermail/squeak-dev/attachments/20161118/d4ba3c3b/attachment.html>


More information about the Squeak-dev mailing list