[squeak-dev] ugg

Hello,

  I just installed the Ogg plug-in in my image, then played a rip of a track
from a CD.  The playback sounds great, except it stutters (stops for half a
second) at random points.  Does anyone else have this problem?  Or, better
yet, has anyone else HAD this problem and fixed it?

  -Aidan

2009/1/7 Aidan Gauland <[hidden email]>:
> Hello,
>
>  I just installed the Ogg plug-in in my image, then played a rip of a track
> from a CD.  The playback sounds great, except it stutters (stops for half a
> second) at random points.  Does anyone else have this problem?  Or, better
> yet, has anyone else HAD this problem and fixed it?
>

not sure, but i suspecting that such pauses can be caused by GC.
I'd recomment to look over memory allocations during playback , and
how often GC invoked.

>  -Aidan
>
>
>



--
Best regards,
Igor Stasenko AKA sig.

Igor Stasenko <siguctua <at> gmail.com> writes:
> not sure, but i suspecting that such pauses can be caused by GC.
> I'd recomment to look over memory allocations during playback, and
> how often GC invoked.

That's kinda what I was thinking, but how do I monitor the garbage collector?  I
tried GCMonitor from here...
ftp://ftp.smalltalkconsulting.com/squeakGarbage/
...but running it raised a MessageNotUnderstood error, so I guess that's too old.

Take a look again I've updated the change set and the readme file.

On 8-Jan-09, at 5:26 PM, Aidan Gauland wrote:

--
=
=
=
========================================================================
John M. McIntosh <[hidden email]>
Corporate Smalltalk Consulting Ltd.  http://www.smalltalkconsulting.com
=
=
=
========================================================================

John M McIntosh <johnmci <at> smalltalkconsulting.com> writes:
>
> Take a look again I've updated the change set and the readme file.

Wow, thanks!  But I can't make any sense of the gcStats.txt file.  I also tried
MessageTally>>spyOn: which seems to indicate that the garbage collector ran many
times while the audio file was played.

Which brings me to my next question: what control do I have over the garbage
collector?  Can I turn it off completely temporarily, or just tell it to relax a
bit?

 -Aidan

Ok, well why don't you post the first 5 lines of the file and I'll  
explain them.


On 9-Jan-09, at 7:13 PM, Aidan Gauland wrote:

--
=
=
=
========================================================================
John M. McIntosh <[hidden email]>
Corporate Smalltalk Consulting Ltd.  http://www.smalltalkconsulting.com
=
=
=
========================================================================

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.

Ok, the headings would be:
statGCTime
oldSpaceEnd
youngSpaceEnd
memoryEnd
fullGCs
fullGCTime
incrGCs
incrGCTime
tenureCount
statMarkCount
statSweepCount
statMkFwdCount
statCompMoveCount
statGrowMemory
statShrinkMemory
statRootTableCount
statAllocationCount
statSurvivorCount
statSpecialMarkCount
statIGCDeltaTime
pendingFinalizationSignals

Most of this data comes from  the
primitiveVMParameter

                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-
only)
                29 number of times make forward loop iterated for current IGC/FGC  
(read-only)
                30 number of times compact move loop iterated for current IGC/FGC  
(read-only)
                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  
reserve.
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  
termination.

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  
loop.

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  
doing:

| 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  
array.

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.

The

        [Smalltalk  setGCBiasToGrowGCLimit: 8*1024*1024] on: Error do: [:ex |  
^self].
        [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 <[hidden email]>
Corporate Smalltalk Consulting Ltd.  http://www.smalltalkconsulting.com
=
=
=
========================================================================

John M McIntosh <johnmci <at> smalltalkconsulting.com> writes:

> 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.

Thanks for the detailed reply!

It stutters with any long, CD-quality audio file; and it's not in the same
places every time.  I think that I should not try to use Squeak for playing CD
rips, unless there's a way to disable garbage collection (or at least minimize
it) while playing a file.

 -Aidan

If you can point to a sound track, and the code you are using I can  
look further

On 13-Jan-09, at 2:03 PM, Aidan Gauland wrote:

--
=
=
=
========================================================================
John M. McIntosh <[hidden email]>
Corporate Smalltalk Consulting Ltd.  http://www.smalltalkconsulting.com
=
=
=
========================================================================