[Vm-dev] Re: [Pharo-dev] Super fast delay

[Eliot Miranda]

Hi Ben,

On Nov 2, 2014, at 6:06 AM, Ben Coman <btc at openInWorld.com> wrote:

> Eliot Miranda wrote:
>> On Wed, Oct 29, 2014 at 12:14 PM, Ben Coman <btc at openinworld.com <mailto:btc at openinworld.com>> wrote:
>>    Holger Hans Peter Freyther wrote:
>>        On Wed, Oct 29, 2014 at 06:54:57PM +0100, Holger Hans Peter
>>        Freyther wrote:
>>            On Wed, Oct 29, 2014 at 10:03:03AM +0100, Norbert Hartl wrote:
>>            Good Evening,
>>        Hi again,
>>        I don't know how you debug startUp issues. I just added an
>>        OrderedCollection
>>        into the systemdictionary and use it as a log..
>>        time ./bin/pharo --nodisplay ./TimerTest3.image eval "(Delay
>>        forSeconds: 3) wait. (Smalltalk at: #Foo) do: [:each |
>>        FileStream stderr nextPutAll: each printString; cr].1"
>>        ... old events from saving the image...
>>        {#handleTimerEvent->7147}
>>        {#handleTimerEvent->7167}
>>        {#resumptionTime->7187}
>>        {#handleTimerEvent->7167}
>>        {#handleTimerEvent->7187}
>>        {#start->true}
>>        {#start->393102159}
>>        {#start->393102159}
>>        {#resumptionTime->3279}
>>        {#handleTimerEvent->279}
>>        {#adjustResum->-393098880}
>>        {#restoreWithActiveDelay->266}
>>        {#adjustResum->-393098601}
>>        1
>>        real    0m0.294s
>>        user    0m0.244s
>>        sys     0m0.048s
>>        So what happens is Delay class>>#startU is called. and
>>        ActiveDelayStartTime is being set to 393102159. Then the
>>        delay is being created and resumptionTime is set to 3279.
>>        At the first time handleTimerEvent runs the milliSecondClock
>>        jumped backwards from 393102159 to 3279 which leads to
>>        an adjustment of the time.
>>        a.) Why does the time jump backwards like this during the
>>        resumption of the image? "3279" is not the old time nor
>>        the new starting time.
>>        b.) So even if that is a "wrap" around. Why does it go
>>        wrong? Are there unit tests for the clock wraps around?
>>    There are no unit tests, I guess since its all done using class
>>    variables its too hard test without disturbing the system.
>>    Now I have spent the last week refactoring this out to the
>>    instance-side of a new class "DelayScheduler" which should help with
>>    getting unit tests.  Its ready for review [1], maybe you could take
>>    a look.
>>    [1] https://pharo.fogbugz.com/__default.asp?14261
>>    <https://pharo.fogbugz.com/default.asp?14261>
>>        Maybe it is the same reason delays just don't work after
>>        image resumption?
>>        The "first" issue appears that when start is being executed
>>        that the clock is still wrong. At the same the clock is
>>        being considered wrapped the resumption time was actually
>>        already "correct' (3279 instead of 393102159+3279).
>>        Does this ring a bell?
>>        holger
>>    btw, its too late in the night for me to try something, but I have
>>    been wondering, should the check for clock roll-over occur
>>    immediately after
>>        TimingSemaphore wait
>>    wakes up. That is, before the Schedule and Finish requests are
>>    handled ???
>> The check for rollover should be thrown away and the system implemented over the VM's support for 64-bit microseconds since 1901.  It's in the VM, it isn't susceptible to rollover for ~ 50,000 years, and doesn't require the millisecond clock to be synced to the second clock, because all times can be derived from the one 64-bit microsecond clock.
>> -- 
>> best,
>> Eliot
> 
> The performance of the Delay timer event loop is noted in the code to be critical, however...
> 
> "Time millisecondClockValue" returns a SmallInteger, which is an immediate object while "Time microsecondClockValue" returns a LargePositiveInteger, which is not.
> 
> So theoretically will calculations and comparisons based on the second be slower ?  Actually my performance testing so far hasn't found it to be slower, but I am interested in the general case.

That comment was written when the context interpreter VM was the standard.  Cog is much faster.  That should more than make up for the small amount of large integer arithmetic the use of 64-bit microseconds involves.  And once we switch to 64-bit Spur the 64-bit microsecond clock will once again be a SmalInteger.  And if your measurements show you there isn't an issue then there isn't an issue.

> 
> cheers -ben