Performance Monitoring

How much garbage?

The first issue is the amount of garbage begin created. If a large number of allocations are being done, then the garbage collector is having to be run frequently and for a relatively long time. But how do we know if we are creating a lot of garbage?

In Smalltalk MT, the garbage collector runs in its own thread and this thread's activity can be monitored using the performance monitor in Windows. You will find this in Control Panel Administrative Tools under Performance. Make sure you are already running the Development environment or your Smalltalk MT application. Run the performance monitor and remove all the existing counters then click the + button. In the add counters dialog we want to track threads here so select Thread in the performance object.  In the "select counter from list" choose "%Processor Time". In the "select instances from list" select all of the STIMAGE items (e.g. STIMAGE/0, STIMAGE/1). Choose Add to add them to the monitor.

You will now see the Smalltalk MT threads being graphed. If you are running the development environment, all of the lines will initially be flat. This is because the Development Environment is not doing anything and since there is no object creation, there is no need for the garbage collector to run. Now let's look at what we would see in a system creating garbage. First we have to find the Garbage Collector thread.

Open a Workspace and force the Garbage Collector to run by calling:

Processor gcForceCycle

One of threads will spike and this is the Garbage Collector Thread.

Now let's put the Garbage collector to work and you will visually see the result.

First we'll use a typical Smalltalk activity like string concatenation. Try this:

2500000 timesRepeat: ['abc','def','ghi'].

And compare this:

str := (String new: 20) asStream.
2500000 timesRepeat: [
str reset.
str nextPutAll: 'abc'.
str nextPutAll: 'def'.
str nextPutAll: 'ghi'.
].

I changed the color of my main thread (always thread 0 - the one that executes the Smalltalk code) to Black and my Garbage Collector thread (found from above) to red.

There are two spikes here. The first shows that garbage collection (in red) is taking the bulk of the processor time. This is because a huge number of strings are being created by the concatenation ('abc','def' creates a new string). This has the effect of making the actual task (in black) take longer since it gets less of the processor.

The second spike shows using the stream. There is only one allocation here (the inital string) then the string concatenation happens on this collection. Here you see a single black spike showing that the main task is taking all of the time and garbage collection is absent. Notice that the task takes considerably less time in the second case.