[squeak-dev] Re: ugg

John M McIntosh johnmci at smalltalkconsulting.com
Sun Jan 11 02:25:23 UTC 2009

Ok, the headings would be:

Most of this data comes from  the

		0 args:	return an Array of VM parameter values;
		1 arg:	return the indicated VM parameter;
		2 args:	set the VM indicated parameter.
	VM parameters are numbered as follows:
		1	end of old-space (0-based, read-only)
		2	end of young-space (read-only)
		3	end of memory (read-only)
		4	allocationCount (read-only)
		5	allocations between GCs (read-write)
		6	survivor count tenuring threshold (read-write)
		7	full GCs since startup (read-only)
		8	total milliseconds in full GCs since startup (read-only)
		9	incremental GCs since startup (read-only)
		10	total milliseconds in incremental GCs since startup (read-only)
		11	tenures of surving objects since startup (read-only)
		12-20 specific to the translating VM
		21	root table size (read-only)
		22	root table overflows since startup (read-only)
		23	bytes of extra memory to reserve for VM buffers, plugins, etc.
		24	memory threshold above which shrinking object memory (rw)
		25	memory headroom when growing object memory (rw)
		26  interruptChecksEveryNms - force an ioProcessEvents every N  
milliseconds, in case the image  is not calling getNextEvent often (rw)
		27	number of times mark loop iterated for current IGC/FGC (read- 
only) includes ALL marking
		28	number of times sweep loop iterated  for current IGC/FGC (read- 
		29	number of times make forward loop iterated for current IGC/FGC  
		30	number of times compact move loop iterated for current IGC/FGC  
		31	number of grow memory requests (read-only)
		32	number of shrink memory requests (read-only)
		33	number of root table entries used for current IGC/FGC (read-only)
		34	number of allocations done before current IGC/FGC (read-only)
		35	number of survivor objects after current IGC/FGC (read-only)
		36  millisecond clock when current IGC/FGC completed (read-only)
		37  number of marked objects for Roots of the world, not including  
Root Table entries for current IGC/FGC (read-only)
		38  milliseconds taken by current IGC  (read-only)
		39  Number of finalization signals for Weak Objects pending when  
current IGC/FGC completed (read-only)
		40 BytesPerWord for this image

Let's look at the values, so allow me to ramble...

statGCTime					123904

This is the millisecond clock time when the sample was taken.  The  
SqueakVMMemoryPolicy will run in two modes, active or passive. In  
passive mode the
SqueakVMMemoryPolicy process wakes up every N (5?) Seconds and takes a  
reading of the GC statistics.  In active mode a semaphore is used to  
signal the SqueakVMMemoryPolicy process to collect data on every  
incremental GC event.

oldSpaceEnd				26725864

The byte offset of old space end. We don't have the start of memory  
here, it's a number elsewhere, but using that and this number we would  
know how many bytes
oldspace uses, this boundary moves higher, or lower.

youngSpaceEnd				27365792
Memory is broken into old space, youngspace, free, forwarding block  
This is the end of allocated young space, the start of free space.

memoryEnd					30183488
This byte offset is the end of memory before the forwarding blocks, so  
let me talk about that space where since we have some other stats on  
forwarding blocks later.

Note: The amount of space reserved for forwarding blocks should be  
chosen to ensure that incremental compactions can usually be done in a  
single pass. However, there should be enough forwarding blocks so a  
full compaction can be done in a reasonable number of passes, say ten.  
(A full compaction requires N object-moving passes, where N = number  
of non-garbage objects / number of forwarding blocks).   di 11/18/2000  
Re totalObjectCount: Provide a margin of one byte per object to be  
used for forwarding pointers at GC time. Since fwd blocks are 8 bytes,  
this means an absolute worst case of 8 passes to compact memory. In  
most cases it will be adequate to do compaction in a single pass.

fullGCs						1

The number of full garbage collection count from zero at image  
startup, on a full GC we do a full GC against all objects in the  
image.  Doing full GC frequently is a bad thing, but perhaps it cannot  
be avoid, depends on the app.

fullGCTime					224
The number of milliseconds accumulative from zero at image startup  
take in full GC work.

incrGCs						1561
Number of incremental garbage collection count from zero at image  
startup, on a incremental GC we scan objects in the root table and in  
the young space.

incrGCTime					1259
The number of milliseconds accumulative from zero at image startup  
take in incremental GC work, on machines today you'll note we can do  
some GC
work in less than 1 milliscond, thus this count of 1,259 is less than  
the total taken, which is 1,561.  In order to ensure events that are  
NEEDED to be triggered with millisecond accuracy we would like to  
complete a incremental GC (IGC) in 1 ms or less.  If for example a IGC  
took say 25ms, then you would have a 25 error in average on a Delay  

tenureCount					12
By default we allocation 4,000 objects,then do a IGC, then see if the  
number of survivors is greater than the survivor count of 2000. If so  
then we tenure all the objects to old space by moving the oldSpaceEnd  
higher. This then ages the objects into oldspace and they are not  
looked at again when doing a IGC.  The 4,000/2,000 numbers where  
picked in the 90's, 16Mhz machines.   Some Squeakers report better GC  
behavior by making  the allocation count & threashold count higher.  How
high is a number that requires some statistical calculations, again  
you want to ensure an IGC over N objects will take about 1 ms.

SqueakVMMemoryPolicy>>calculateGoals  contains some sample not used  
code for consideration and experimentation.
Also see
	SmalltalkImage current  vmParameterAt: 5 put: 8000.  "do an  
incremental GC after this many allocations"
	SmalltalkImage current  vmParameterAt: 6 put: 4000.  "tenure when  
more than this many objects survive the GC"

statMarkCount				13331

The Squeak GC algorithm uses a mark algorithm to mark which objects  
are accessible, then a sweep to mark objects that are free versus  
used, then a move and compacting event that consolidates the free  
space into one chunk at the end of young space.

In this case we know we reached the 4,000 limit of allocation by the  
statAllocationCount and using the root table and youngspace marked   
13,331 as used.

statSweepCount				5579

At the end of the IGC we swept 5,579 object, which means 5,579 objects  
(free or allocated where in young space). The other data  
statSurvivorCount at
1,591 and the allocation count of 4,000 means on the last IGC there  
were 1,579 object alive, we allocated 4,000 more, and on the IGC only  
found 1,591 alive.

statMkFwdCount				109

This is a count of the number times thru the forwarding block loop.

statCompMoveCount			109
This is a count of the number times thru the compression move block  

statGrowMemory				1

memoryEnd is the limit of memory, but it might not be the limit of  
available memory, if so the memoryEnd can move by providing more  
memory. This counts the number times this happens. This happens when  
free memory becomes too low, or a large object cannot be allocated.

statShrinkMemory			1

When free space becomes too large, then we give some back to the  
operating system.   This counts how many times this happens.   The low  
memory and too much free memory thresholds are arbitrarily set values.
		24	memory threshold above which shrinking object memory (rw)
		25	memory headroom when growing object memory (rw)

Excessive statGrowMemory/statShrinkMemory incrrementing points to a  
problem where you are cycling between a high/low value exceeding the  
limits, this is expensive and the thresholds should be adjust to avoid  
thi. s

statRootTableCount			331
"Record that the given oop in the old object area points to an object  
in the young area. HeaderLoc is usually = oop, but may be an addr in a  
forwarding block."

This is the number of roots, the number of objects in oldspace  
(usually) that point to some object in young space. The IGC needs this  
information to determine which objects are live in young space.    
Other Smalltalk might call this the remember table.

Now a bit about Squeak's implementation, some other smalltalk record  
what the object is and what the slot is, this can require a lot of  
memory and require memory to be allocated when you can't allocate  
memory (crash).  Squeak records the object, but now if this is a  
Collection then later when we mark we must visit ALL the slots in the  
object to determine which object is in young space.   How this issue  
shows up in Squeak is stories about people allocating large  
collections then for some reason squeak becomes slow, but if they do a  
full GC, squeak becomes fast.

The SqueakVMMemoryPolicy>>calculateGoals attempts to solve this by  

| target |

	(statMarkCount ) > (statAllocationCount*2)
		ifTrue: [[Smalltalk forceTenure] on: Error do: [:ex | ]].  "Tenure  
if we think too much root table marking is going on"

If we think took much marking is going on because the root table  
counting is too high then we invoke Smalltalk forceTenure which  
tenures everything to oldspace, and
hopefully removing the problem object from the root table. Although  
this seem excessive too much mark scanning means less CPU time for  
byte code interpretation.

statAllocationCount			4000
At the start of the IGC, this is the number of objects that were  
allocated, this helps determine if the IGC was done as a result of  
object allocation, or because some other allocation issue required the  
IGC to run to fix an issue, say a large object being allocated

statSurvivorCount			1591
At the end of the IGC this is the number of objects that still were  
alive, using the statAllocationCount, and statSurvivorCount you might  
be able to determine values that ensure a IGC doesn't tenure objects,  
yet finishes in about 1 ms.

statSpecialMarkCount		633
count the number of objects we mark which are accessible by the  
special objects, receiver, method, activecontext, message selector,  
method class, receiver class,etc, and the internal remapping objects  

statIGCDeltaTime			1

For this IGC, it took 1 ms

pendingFinalizationSignals	0

This is the number of weak objects that have "died" in this GC cycle.


Obviously figuring out what all this data means is a chore, so email  
me not the list of a sample file where you have the problem with  
playback. If you
can determine the millisecond/second count where the problem occured  
at, it would be helpful.


I'll note Squeak out of the box has a bias to compact memory, there is  
a condition that Squeak can enter into where when you allocate that  
next object memory is full, then you do a IGC and get back a reasonal  
number of bytes, you allocate the object, then fail on the next one,  
then a IGC, get back some bytes, allocate the object, fail on the next  
one... This then triggers 10 of thousands of IGC events a second,  
Squeak appears to hang.


	[Smalltalk  setGCBiasToGrowGCLimit: 8*1024*1024] on: Error do: [:ex |  
	[Smalltalk setGCBiasToGrow: 1] on: Error do: [:ex | ^self].

in SqueakVMMemoryPolicy startUp

Alters the allocation behaviour to grow memory versus doing just  
another IGC, so bias to grow memory.   However we can't grow memory  
forever so
the setGCBiasToGrowGCLimit to 8MB to indicate where a full GC should  
occur after 8MB of biased growth.  This avoid the bug in the memory  
allocation logic.

On 10-Jan-09, at 3:24 PM, Aidan Gauland wrote:

> John M McIntosh <johnmci <at> smalltalkconsulting.com> writes:
>> Ok, well why don't you post the first 5 lines of the file and I'll
>> explain them.
> Ok, here they are...
> 123904	26725864	27365792	30183488	1	224	1561	1259	12	13331	5579	109	 
> 109	1	1
> 331	4000	1591	633	1	0	
> 129430	27191724	27961664	30183488	1	224	1567	1265	13	1530	4126	192
> 192	1	1	36	4000	142	351	2	0	
> 133846	27191724	29113412	30183488	1	224	1572	1270	13	3441	4341	318
> 318	1	1	44	4000	370	350	2	0	
> 139371	27191724	29181436	30183488	1	224	1578	1282	13	3793	4411	270
> 270	1	1	44	4000	418	350	2	0	
> 143936	27191724	29757020	30183488	1	224	1583	1294	13	4263	4474	333
> 333	1	1	44	4000	479	314	2	0	
> Oh, and I had to do "SqueakVMMemoryPolicy new; collectStatistics:  
> true; run" to
> make it create a file; just "SqueakVMMemoryPolicy run" didn't create  
> a file.

John M. McIntosh <johnmci at smalltalkconsulting.com>
Corporate Smalltalk Consulting Ltd.  http://www.smalltalkconsulting.com

More information about the Squeak-dev mailing list