[Cuis-dev] Jitter source during benchmarks

[Nicolás Papagna Maldonado]

Hi Martin!

On Tue, May 12, 2026 at 6:05 PM Martin McClure <martin at hand2mouse.com>
wrote:

> Hi Nico,
>
> I would definitely suspect GC. You've already eliminated full/incremental
> GC. Does Cuis keep statistics on when scavenges are done? It's a
> sub-millisecond difference between the peaks. ~700 microseconds seems like
> maybe a bit long for a scavenge, but not unbelievable.
>
> To eliminate memory allocation or GC effects, you could try running a full
> GC between each repetition of the test and see whether there is still a
> bimodal distribution.
>
Sorry I was not clear enough, my bad.
That's what I did. Before I run each test suite I run a full GC:

testSuites collect: [ :testSuite | self profile: [ testSuite run ] ].

I implemented #profile: as follows:

profile: aBlock

    Smalltalk garbageCollect.
    startVMStats := Smalltalk getVMParameters.
    ticksPerMs := Time highResTimerTicksPerMillisecond.
    startTicks := Time primHighResClock.

    aBlock value.

    endTicks := Time primHighResClock.
    endVMStats := Smalltalk getVMParameters.

    "returned result includes
        elapsed time based on (endTicks-startTicks)/ticksPerMs.
        Full GC count & ms based on endVMStats - startVMStats
        Incremental GC count & ms based on endVMStats - startVMStats"

No GC activity was observed (full or incremental) on all the 50 Aconcagua
test suite runs.


> Regards,
>
> -Martin
> On 5/12/26 12:17 PM, Nicolás Papagna Maldonado via Cuis-dev wrote:
>
> Hi folks,
>
> I'm in the process of doing performance benchmarks of my Code Coverage
> tool for my thesis, and I've encountered something interesting while
> measuring the test execution times of the Aconcagua package.
>
> *Observation:*
> When running the Aconcagua test suite 150 times in a clean image, the
> execution times are not normally distributed. Instead, they fall into two
> distinct "modes":
>
> [image: image.png]
> A Base Mode (~6.28 ms): Representing roughly 72% of the iterations.
> A Spike Mode (~7.0 ms): Representing roughly 28% of the iterations.
>
> As the next plot shows, the spikes are not random; they seem to be kind-of
> deterministic (roughly every 4th iteration).
> I think these perturbations are visible because I'm taking very small
> measurements (~6.28 ms).
> [image: image.png]
>
> *Question:*
> I am trying to isolate whether this "heartbeat" is originating from within
> the Cuis image or the VM/OS layer (I'm thinking of VM timer/events, maybe
> UI timers?)
> Does anyone know what could be causing this?
> Are there any known events that run at this particular frequency?
>
> I repeated the experiment a couple of times and the perturbations are
> consistent (in terms of ms and frequency).
>
> *Methodology:*
>
>    - Measurements were taken in batches of 50 test runs.
>    - Each batch was run in a fresh image, waiting 2 minutes for the VM to
>    stabilize Cuis code.
>    - 10 warmup runs were done and discarded before measuring test run
>    times.
>    - Measurements were taken using Time primHighResClock and converted to
>    ms using Time highResTimerTicksPerMillisecond.
>    - VM stats were collected before and after measurements. A full GC was
>    run before taking measurements.
>    - No GC activity was observed while measuring the tests run (VM stats
>    report no full nor incremental GCs).
>    - The test suite was created and run from a workspace
>
> *Cuis environment:*
>
>    - Cuis Smalltalk commit:
>    https://github.com/Cuis-Smalltalk/Cuis-Smalltalk-Dev/commit/b221722348cc46ebb9f5d9f3a057a3f361aa3d55
>    - Code Coverage commit:
>    https://github.com/npapagna/cuis-code-coverage/commit/db19de02250a3fd50dfc4e0b4d0893b656e31e9b
>    - Aconcagua commit:
>    https://github.com/Cuis-Smalltalk/Measures/commit/05aa02aada64f7b64898a5e1452ae8fb76f79427
>
> *Machine environment:*
>
>    - Model Name: MacBook Pro
>    - Model Identifier: MacBookPro18,3
>    - Model Number: MKGR3LL/A
>    - Chip: Apple M1 Pro
>    - Total Number of Cores: 8 (6 Performance and 2 Efficiency)
>    - Memory: 16 GB
>    - System Firmware Version: 13822.81.10
>    - OS Loader Version: 13822.81.102
>    - APPLE SSD AP0512R (NVMe, avg read 5671 MB/s, avg write 5670 MB/s)
>    - macOs 26.3 (25D125)
>    - A dedicated fresh profile was created for the benchmarks (indexing,
>    time machine, screen lock/saver, display shutdown, bluetooth and wifi
>    disabled).
>
> Thanks in advance,
> Nico PM
>
>
>

-- 

Nicolás Papagna
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.cuis.st/mailman/archives/cuis-dev/attachments/20260512/5465914d/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image.png
Type: image/png
Size: 48058 bytes
Desc: not available
URL: <http://lists.cuis.st/mailman/archives/cuis-dev/attachments/20260512/5465914d/attachment-0002.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image.png
Type: image/png
Size: 175232 bytes
Desc: not available
URL: <http://lists.cuis.st/mailman/archives/cuis-dev/attachments/20260512/5465914d/attachment-0003.png>