Norbert Hartl wrote:
Am 30.10.2014 um 12:52 schrieb Ben Coman <btc@openinworld.com>:
Eliot Miranda wrote:
On Wed, Oct 29, 2014 at 12:14 PM, Ben Coman <btc@openinworld.com <mailto:btc@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 I'll give it a go. cheers -ben
Super, thanks in advance,
Norbert
This is ready for review as "Delay refactoring (part 2) - change from milliseconds to microseconds" https://pharo.fogbugz.com/default.asp?14353 Note that this continues on from "Delay refactoring (part 1) - move scheduler from class-side to instance-side of its own class" https://pharo.fogbugz.com/default.asp?14261 So load part 1 first if you only want to see the from milliseconds to microseconds changes. Now if you don't like part 1, I'll do the work to break out part 2 on its own - but it was simpler for me to work on part 2 since: * with instances I could define, run and debug tests without interference from the live system-delay-scheduler. * the code swapping (newCodeEnabled) pattern I'd used for part 1 helped. * eliminating the clock rollover conditional simplifies what I am planning for part 3 I don't have the virtual machine environment to replicate the problem, so please report if it this has any effect. cheers -ben