<div dir="ltr">Hi David,<div><br></div><div>    forgive the lack of response.  I needed to think about this...</div><div class="gmail_extra"><br><br><div class="gmail_quote">On Wed, Mar 5, 2014 at 4:59 PM, David T. Lewis <span dir="ltr">&lt;<a href="mailto:lewis@mail.msen.com" target="_blank">lewis@mail.msen.com</a>&gt;</span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><br>
On Tue, Mar 04, 2014 at 03:13:26PM -0800, Eliot Miranda wrote:<br>
&gt;<br>
&gt; On Tue, Mar 4, 2014 at 2:37 PM, Sven Van Caekenberghe &lt;<a href="mailto:sven@stfx.eu">sven@stfx.eu</a>&gt; wrote:<br>
&gt; &gt;<br>
&gt; &gt; There is a big difference in how DateAndTime class&gt;&gt;#now works in 2.0 vs<br>
&gt; &gt; 3.0. The former uses #millisecondClockValue while the latter uses<br>
&gt; &gt; #microsecondClockValue. Furthermore 2.0 does all kind of crazy stuff with a<br>
&gt; &gt; loop and Delays to try to improve the accuracy, we threw all that out.<br>
&gt; &gt;<br>
&gt; &gt; Yeah, I guess the clock is just being updated slowly, maybe under heavy<br>
&gt; &gt; load. The question is where that happens. I think in the virtualised OS.<br>
&gt; &gt;<br>
&gt;<br>
&gt; That makes sense.  In the VM the microsecond clock is updated on every<br>
&gt; heartbeat and the heartbeat should be running at about 500Hz.  Can anyone<br>
&gt; with hardware confirm that in 3.0 the time on linux does indeed increase at<br>
&gt; about 500Hz?<br>
&gt;<br>
&gt; Note that even in 2.0 the time is being derived from the same basis.  In<br>
&gt; Cog, the effective time basis is the 64-bit microsecond clock maintained by<br>
&gt; the heartbeat and even the secondClock and millisecondClock are derived<br>
&gt; from this.  So its still confusing why there should be such a difference<br>
&gt; between 2.0 and 3.0.<br>
&gt;<br>
<br>
The separate thread for timing may be good for profiling, but it is not such<br>
a good idea for the time primitives. When the image asks for &quot;time now&quot; it<br>
means now, not whatever time it was when the other thread last took a sample.<br>
By reporting the sampled time, we get millisecond accuracy (or worse) reported<br>
with microsecond precision.<br></blockquote><div><br></div><div>Yes, you&#39;re quite right about the lack of accuracy being broken.  You&#39;re not right about the heartbeat thread though, here&#39;s why, and this took me some time to remember.</div>
<div><br></div><div>gettimeofday is quite slow.  It takes a timezone argument which needs to be looked up.  So if at all possible calls to gettimeofday should be minimised.  Of course, using it to get the time at the Smalltalk level is fine.  Where it /isn&#39;t/ fine is in polling for events.  The VM can enquire of the time at a very high frequency, and if it calls gettimeofday every time through its checkForEvents loop this can add up to significant time. One of the uses here is in seeing if the next scheduled delay fire time has been reached. Hence, prompted by Andreas I implemented time update in the heartbeat thread.  The idea here is that the time is accessed only at heartbeat frequency (say 500Hz), not at interrupt check frequency, which is heartbeat frequency + stack page overflow frequency, which can be 250KHz (!!).</div>
<div><br></div><div>For example here&#39;s data from profiling 10 timesRepeat: [0 tinyBenchmarks]</div><div><br></div><div><div>**Events**</div><div>Process switches<span class="" style="white-space:pre">        </span>729 (10 per second)</div>
<div>ioProcessEvents calls<span class="" style="white-space:pre">        </span>3613 (50 per second)</div><div>Interrupt checks<span class="" style="white-space:pre">        </span>38635 (530 per second)</div><div>Event checks<span class="" style="white-space:pre">        </span>42300 (580 per second)</div>
<div>Stack overflows<span class="" style="white-space:pre">        </span>17461252 (239346 per second)  &lt;&lt; deep recursion</div><div>Stack page divorces<span class="" style="white-space:pre">        </span>0 (0 per second)</div></div>
<div><br></div><div><br></div><div>deep recursion from the benchFib method causes a high rate of stack overflows, and the VM uses stack overflow to check for events.  The heartbeat forces a stack overflow by setting the stack limit suitably.  So if check for events uses the time now, rather than the time set in te heartbeat, it would be calling gettimeofday at 240KHz, not 500Hz, a big difference.  The heartbeat time is then used to reduce the frequency of ioProcessEvents calls to 50Hz.<br>
</div><div><br></div><div>But it wasn&#39;t until today in the shower that I realised that of course the VM /doesn&#39;t/ need to use the heartbeat time for the time accessed at the Smalltalk level.  So primUTCMicrosecondClock should use ioUTCMicrosecondsNow while the event checking code should remain unchanged.  The effect of this is to increase the accuracy of Smalltalk-level time, while keeping the Delay accuracy at the heartbeat frequency, or a jitter of 2ms or so.  And of course its simpel to modify the code to use a flag so people can experiment.</div>
<div><br></div><div>But for me the right compromise is to access the current time in the time primitives but continue to use the heartbeat time for checking for events.  Does that make sense to you David?</div><div><br></div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">
<br>
If you collect primUTCMicrosecondClock in a loop with the primitive as<br>
implemented in Cog, then plot the result, you get a staircase with long<br>
runs of the same time value, and sudden jumps every one and a half milliseconds<br>
or so. The equivalent plot for the primitive as implemented in the interpreter<br>
VM is a smoothly increasing slope.<br>
<br>
To illustrate, if you run the example below with Cog to collect as many<br>
&quot;time now&quot; data points as possible within a one second time period, you find<br>
a large number of data points at microsecond precision, but only a small number<br>
of distinct time values within that period.<br>
<br>
  &quot;Cog VM&quot;<br>
  oc := OrderedCollection new.<br>
  now := Time primUTCMicrosecondClock.<br>
  [(oc add: Time primUTCMicrosecondClock - now) &lt; 1000000] whileTrue.<br>
  oc size. ==&gt; 2621442<br>
  oc asSet size. ==&gt; 333<br>
<br>
In contrast, an interpreter VM with no separate timer thread collects fewer samples<br>
(because it is slower) but the sample values are distinct and increase monotonically<br>
with no stair stepping effect.<br>
<br>
  &quot;Interpreter VM&quot;<br>
  oc := OrderedCollection new.<br>
  now := Time primUTCMicrosecondClock.<br>
  [(oc add: Time primUTCMicrosecondClock - now) &lt; 1000000] whileTrue.<br>
  oc size. ==&gt; 246579<br>
  oc asSet size. ==&gt; 246579<br>
<br>
Dave<br>
<br>
</blockquote></div><br><br clear="all"><div><br></div>-- <br>best,<div>Eliot</div>
</div></div>