Hi,
In recent VMs (Mac and Unix), SmalltalkImage current vmStatisticsReportString is broken, in that it returns nonsense data for GC times:
... GCs 1,145,798 (84ms between GCs) full 3914 totalling 723,736,998ms (755.3% uptime), avg 184909.8ms incr 1141884 totalling 248,056,609ms (258.9% uptime), avg 217.2ms tenures 14,222 (avg 80 GCs/tenure) Since last view 72 (49ms between GCs) uptime 3.5s full 0 totalling 0ms (0.0% uptime) incr 72 totalling 15,110ms (426.1% uptime), avg 209.9ms tenures 0
primitiveVMParameter in the most recent version of VMMaker package was changed. Does the image-side code need to be adapted or is this a bug in the primitive?
Thanks, Adrian
___________________ http://www.adrian-lienhard.ch/
On Aug 6, 2010, at 2:39 53PM, Adrian Lienhard wrote:
Hi,
In recent VMs (Mac and Unix), SmalltalkImage current vmStatisticsReportString is broken, in that it returns nonsense data for GC times:
... GCs 1,145,798 (84ms between GCs) full 3914 totalling 723,736,998ms (755.3% uptime), avg 184909.8ms incr 1141884 totalling 248,056,609ms (258.9% uptime), avg 217.2ms tenures 14,222 (avg 80 GCs/tenure) Since last view 72 (49ms between GCs) uptime 3.5s full 0 totalling 0ms (0.0% uptime) incr 72 totalling 15,110ms (426.1% uptime), avg 209.9ms tenures 0
primitiveVMParameter in the most recent version of VMMaker package was changed. Does the image-side code need to be adapted or is this a bug in the primitive?
Thanks, Adrian
It's been changed to a microsecond clock value in recent VM's on Unix/Mac. So yes, you have to adjust code in image based on which VM version / Platform you are running on to report a non-nonsense value consistently :)
Cheers, Henry
Hi Henrik,
On Aug 6, 2010, at 14:55 , Henrik Johansen wrote:
primitiveVMParameter in the most recent version of VMMaker package was changed. Does the image-side code need to be adapted or is this a bug in the primitive?
Thanks, Adrian
It's been changed to a microsecond clock value in recent VM's on Unix/Mac.
Ah, I didn't notice the change of the clock. So, it's easy to fix. But the Windows VM doesn't have that (yet)?
Cheers, Adrian
So yes, you have to adjust code in image based on which VM version / Platform you are running on to report a non-nonsense value consistently :)
Cheers, Henry
On Fri, Aug 06, 2010 at 04:24:10PM +0200, Adrian Lienhard wrote:
Hi Henrik,
On Aug 6, 2010, at 14:55 , Henrik Johansen wrote:
primitiveVMParameter in the most recent version of VMMaker package was changed. Does the image-side code need to be adapted or is this a bug in the primitive?
Thanks, Adrian
It's been changed to a microsecond clock value in recent VM's on Unix/Mac.
Ah, I didn't notice the change of the clock. So, it's easy to fix. But the Windows VM doesn't have that (yet)?
Oops, I think that's my fault - I didn't coordinate with Andreas on making sure the platform sources for this got updated properly last time around. I think that the last widely advertised Windows VM was missing the necessary updates as a result of this, and possibly is giving incorrect timing as a result.
Can you try downloading the latest Windows VM from squeakvm.org and see if the problem goes away? Using that VM with a Squeak trunk image I get output like this:
'uptime 42h16m38s memory 19,953,968 bytes old 15,092,452 bytes (75.6%) young 3,363,080 bytes (16.9%) used 18,455,532 bytes (92.5%) free 1,498,436 bytes (7.5%) GCs 2,040 (74607ms between GCs) full 2 totalling 86ms (0.0% uptime), avg 43.0ms incr 2038 totalling 189ms (0.0% uptime), avg 0.0ms tenures 7 (avg 291 GCs/tenure) Since last view 1,652 (227ms between GCs) uptime 375.6s full 1 totalling 45ms (0.0% uptime), avg 45.0ms incr 1651 totalling 134ms (0.0% uptime), avg 0.0ms tenures 6 (avg 275 GCs/tenure) '
The supposed 42 hours uptime is completely wrong, but the rest looks reasonable.
Dave
On Fri, Aug 6, 2010 at 5:55 AM, Henrik Johansen < henrik.s.johansen@veloxit.no> wrote:
On Aug 6, 2010, at 2:39 53PM, Adrian Lienhard wrote:
Hi,
In recent VMs (Mac and Unix), SmalltalkImage current
vmStatisticsReportString is broken, in that it returns nonsense data for GC times:
... GCs 1,145,798 (84ms between GCs) full 3914 totalling 723,736,998ms (755.3%
uptime), avg 184909.8ms
incr 1141884 totalling 248,056,609ms (258.9% uptime),avg 217.2ms
tenures 14,222 (avg 80 GCs/tenure)Since last view 72 (49ms between GCs) uptime 3.5s full 0 totalling 0ms (0.0% uptime) incr 72 totalling 15,110ms (426.1% uptime), avg 209.9ms tenures 0
primitiveVMParameter in the most recent version of VMMaker package was
changed. Does the image-side code need to be adapted or is this a bug in the primitive?
Thanks, Adrian
It's been changed to a microsecond clock value in recent VM's on Unix/Mac.
Is this really the case? If so, I think it is completely unnecessary. In the Cog VM I also use microseconds to sum GC times but when they are answered through getVMParameters they are converted to milliseconds (dividing by 1000 is not hard to do). So why change the external interface of the primitive when so much existing code depends on it?
confused, Eliot
So yes, you have to adjust code in image based on which VM version / Platform you are running on to report a non-nonsense value consistently :)
Cheers, Henry
On Sun, Aug 08, 2010 at 02:22:25PM -0700, Eliot Miranda wrote:
On Fri, Aug 6, 2010 at 5:55 AM, Henrik Johansen < henrik.s.johansen@veloxit.no> wrote:
On Aug 6, 2010, at 2:39 53PM, Adrian Lienhard wrote:
Hi,
In recent VMs (Mac and Unix), SmalltalkImage current
vmStatisticsReportString is broken, in that it returns nonsense data for GC times:
... GCs 1,145,798 (84ms between GCs) full 3914 totalling 723,736,998ms (755.3%
uptime), avg 184909.8ms
incr 1141884 totalling 248,056,609ms (258.9% uptime),avg 217.2ms
tenures 14,222 (avg 80 GCs/tenure)Since last view 72 (49ms between GCs) uptime 3.5s full 0 totalling 0ms (0.0% uptime) incr 72 totalling 15,110ms (426.1% uptime), avg 209.9ms tenures 0
primitiveVMParameter in the most recent version of VMMaker package was
changed. Does the image-side code need to be adapted or is this a bug in the primitive?
Thanks, Adrian
It's been changed to a microsecond clock value in recent VM's on Unix/Mac.
Is this really the case? If so, I think it is completely unnecessary. In the Cog VM I also use microseconds to sum GC times but when they are answered through getVMParameters they are converted to milliseconds (dividing by 1000 is not hard to do). So why change the external interface of the primitive when so much existing code depends on it?
confused, Eliot
Background is at http://bugs.squeak.org/view.php?id=7458.
The VMMaker changes are hidden in the version history due to some merging (there are two VMMaker-xxx.165.mcz entries, which caused the VMMaker-dtl.164 version to be hidden in the version history), but were introduced here:
Name: VMMaker-dtl.164 Author: dtl Time: 28 March 2010, 1:44:25 pm UUID: 8637033b-c991-462f-9970-318688bbc998 Ancestors: VMMaker-eem.163
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.
The key points are: - Implementation of #primitiveVMParameter implimentation was changed. - There is no change to #primitiveMillisecondClock. - The new #primitiveMicrosecondClock and #primitiveUtcWithOffset are available for future use, but are currently unreferenced.
As far as I know, the changes to #primitiveVMParameter had no effect on any code in the image (although I am not certain, perhaps John can confirm). There was, however a problem in one version of the Windows VM that led to the discussion. This was a mistake, caused by my misguided attempt to provide backward compatibility, leading to Andreas being unaware of required platform changes. The issue should be resolved now, so hopefully there is no problem ongoing.
Dave
On 2010-08-14, at 11:36 AM, David T. Lewis wrote:
Is this really the case? If so, I think it is completely unnecessary. In the Cog VM I also use microseconds to sum GC times but when they are answered through getVMParameters they are converted to milliseconds (dividing by 1000 is not hard to do). So why change the external interface of the primitive when so much existing code depends on it?
confused, Eliot
Ya, guilty, there should be a check in the vmStatisticsReportString to see if the primitiveMicrosecondClock is there then do the division, you could do the division in the prim, but I'd rather just make the raw micro seconds available to the client, otherwise you just end up adding rounding errors to whatever calculations/decisions he is making.
=========================================================================== John M. McIntosh johnmci@smalltalkconsulting.com Twitter: squeaker68882 Corporate Smalltalk Consulting Ltd. http://www.smalltalkconsulting.com ===========================================================================
vm-dev@lists.squeakfoundation.org
-
Adrian Lienhard -
David T. Lewis -
Eliot Miranda -
Henrik Johansen -
John M McIntosh