getVMParameters broken

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
7 messages Options
Reply | Threaded
Open this post in threaded view
|

getVMParameters broken

Adrian Lienhard

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/

Reply | Threaded
Open this post in threaded view
|

Re: getVMParameters broken

Henrik Sperre Johansen

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
Reply | Threaded
Open this post in threaded view
|

Re: getVMParameters broken

Adrian Lienhard

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

Reply | Threaded
Open this post in threaded view
|

Re: getVMParameters broken

David T. Lewis
 
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

Reply | Threaded
Open this post in threaded view
|

Re: getVMParameters broken

Eliot Miranda-2
In reply to this post by Henrik Sperre Johansen
 


On Fri, Aug 6, 2010 at 5:55 AM, Henrik Johansen <[hidden email]> 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

Reply | Threaded
Open this post in threaded view
|

Re: getVMParameters broken

David T. Lewis
 
On Sun, Aug 08, 2010 at 02:22:25PM -0700, Eliot Miranda wrote:

>  
> On Fri, Aug 6, 2010 at 5:55 AM, Henrik Johansen <
> [hidden email]> 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

Reply | Threaded
Open this post in threaded view
|

Re: getVMParameters broken

johnmci
 

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 <[hidden email]>   Twitter:  squeaker68882
Corporate Smalltalk Consulting Ltd.  http://www.smalltalkconsulting.com
===========================================================================





smime.p7s (3K) Download Attachment