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
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 ??? cheers -ben