[squeak-dev] Precision of VM parameters 8, 10, 36, and 38 for GC statistics (was: The Inbox: Chronology-Core-mt.50.mcz)

David T. Lewis lewis at mail.msen.com
Sun Nov 3 22:57:30 UTC 2019

Keeping this on squeak-dev because it it pertains to semantics and
usage in Squeak as opposed to how to implement it in the VM.

I propose that the VMs should report GC metrics as millisecond values
with microsecond precision, and the Float return values be used to
implement this when the values are not whole milliseconds. Mainly this
affects the interpreter VM but would also be beneficial for Cog/Spur
to make the higher precision measurements accessible. A Squeak Float
can be conveniently returned by a primitive, and has magnitude sufficient
for five hours worth of microseconds.

Comments welcome, and I'll put the implementation into the interpreter VM
if no one objects. I can add it to oscog also if people like the idea.

The various VMs keep track of GC time internally to microsecond precision.
The oscog VMs and SqueakJS all correctly report the VM parameters to lower
millisecond precision, and the traditional interpreter VMs incorrectly
report the values to microsecond precision. Here, "correct" means compliant
with the documented interface in the method comments in both the VM and
the image.


Early VMs reported GC timings in milliseconds. In January 2010,
John McIntosh proposed a set of VM changes to enable microsecond
timing precision in VM metrics:


This proposal was tracked on Mantis:


And John's changes were incorporated into the VM here:

   Name: VMMaker-dtl.164
   Author: dtl
   Time: 28 March 2010, 1:44:25 pm
   VMMaker 4.0.1
   Reference Mantis 7458: [Vm-dev] microsecond timing for GC work
   Add primitiveMicrosecondClock and microsecond GC instrumentation by John McIntosh.
   Add primitiveUtcWithOffset.
   Fix signature of Interpreter>>dumpImage: (pointer declared as int).
   The new primitives require support in the platform code. Default
   implementations are provided to allow compilation without these
   platforms updates, see CCodeGenerator>>writeDefaultMacrosOn:.
   Without platform updates, the GC instrumentation falls back to millisecond
   precision, the primitiveMicrosecondClock primitive answers (incorrectly)
   a millisecond value, and primitiveUtcWithOffset fails the primitive.

I believe that our intention at the time was change to directly reporting
these parameters in microseconds and update the method comments accordingly,
but for whatever reason this didn't happen. The comments remained the
same and the (interpreter) VM now reported whole microseconds rather than
milliseconds for parameters 8 and 10, which conflicted with the method
comments and with the original semantics.

Meanwhile, Cog was progressing in the oscog branch of VMMaker and
platform sources, delivering improvements for GC internals and metrics
collection, but continuing to honor the documented interface for
these VM parameters. This was probably done early in in the oscog
development branch, as the oldest entry in the VMMaker respository
(VMMaker.oscog-eem.55 from April 2011) is rounding the VM parameters
8, 10, and 38 back to the spicified millisecond precision.

Now we have a well established expectation of the GC parameters
being reported in milliseconds, so for example Chronology-Core-mt.50
in the inbox depends on that behavior. Changing that convention would
be messy now, while it is fairly easy to allow the parameter values
to take Float values when higher precision is needed.

Changing all the VMs to answer millisecond values, with either integer
milliseconds or Float for higher precision, will give consistent semantics.
I tested an implementation for the interpreter VM, and it works well.


On Sat, Nov 02, 2019 at 11:15:42AM -0400, David T. Lewis wrote:
> +1 for inclusion, with the following suggested tweak:
> Use printShowingMaxDecimalPlaces: rather than roundTo: in the percent
> GC display, and also drop the space before the $%. Thus the last line
> of the method would be:
>   pair second } ]), (' {1}% GC time.' format: {gcTime / elapsedTime * 100 printShowingMaxDecimalPlaces: 5})
> Rationale: Rounding may not do what you expect with some float calculations.
> This may be VM dependent (I can explain in a separate follow up message),
> but for example I saw occasional results like this:
>  '85,200 per second. 11.7 microseconds per run. 2.3850000000000002 % GC time.'
> Using printShowingMaxDecimalPlaces: will ensure this instead:
>  '85,200 per second. 11.7 microseconds per run. 2.385% GC time.'
> Dave

More information about the Squeak-dev mailing list