Bruce writes:
 
> >              Average:      Total:   Total millisecs:
> >Test Name :      Ticks         Ticks   CPU   Elapsed
> >----------: ----------  ------------ ------- -------
> >empty     :       12.4         1,235       0       0
> >ldcws     :       76.0         7,604       1       0
>
> This seems long, about 60 ticks. Does this represent a
> cache flush? I would think that on a uniprocessor system,
 
This should represent the cost of a memory/bus transaction.
 
> >FLOCK f   :     2479.6       295,258      10       9     5405
>
> These last three measurements could be the start of something
> big... any time you figure out how to stuff more than one
> CPU second into one elapsed second, you've broken a major
 
Oops: I hadn't meant to reveal my TimeWarpProgramming (tm) system, yet.
 
Seriously, this just reflects a bug in either PROCTIME or TIMER, since
I *always* do my timing loops as follows:
 
      et := timer;         {get time since something, millisecs}
      ct := proctime;      {get my CPU time, millisecs}
 
      ...code to be timed...
 
      ct := proctime - ct;
      et := timer - et;
      ...code to compensate for timer rollover...
      ...code to make sure ratio of ct/et >= 0.95 (if not, redo timing loop)
         (for CPU bound timings, only ... if you don't get a ratio
          of close to 100%, then your timings are probably distorted
          by impact of multiprogramming)
 
Thus, if timer and proctime work correctly, the value of ct (delta CPU)
*must* be <= the value of et (delta elapsed time).
 
Note: you never want to do:
 
      et := timer;
      ct := proctime;
      ...code to be timed...
      et := timer - et;
      ct := proctime - ct;
      ...code to compensate for timer rollover...
 
because there could be a long delay between the second timer call and the
second proctime call if you get swapped out, and because the second
proctime will include the cost of the timer.
 
> >FLOCK mIO :    18622.0     1,862,200      56      59        0
> >FLOCK mIO :    19564.6     1,956,462      61      61        0
>
> Not sure I understand these two.
 
Oops...I ran several timing tests.  The second could represent interactions
from other processes.  For this type of test, I generally use the
times from the fastest test run.  I forgot to delete the second of the
above lines.
 
> >FLOCK mIO :   437457.2    43,745,720   1,331   1,368     1000
> ...
> >FLOCK mIO :  2174238.0   217,423,816   6,720   6,795     5405
>
> >The "FLOCK mIO" is a mapped file HPOPEN (I/O, lock, shr, long-mapped).
> >Note that its times vary *DRAMATICALLY* based on how many pages
> >are in memory.
>
> I presume -- I _hope_ -- that this varies with the number of _dirty_
> pages in memory, not just the number of pages. Does it?
 
Good question ... no, these are *CLEAN* pages in memory.  If you want,
I could trivially modify the test program to count the number of dirty
pages as well.  (Actually, it already counts the number of pages of
the file in memory, frozen, dirty, referenced, in-motion-in, recoverable
overlay candidates, and more (?).)
 
...
 
I did...the pages are present, clean, and not referenced recently.
(The FUNLOCK doesn't reference the pages)
 
Stan Sieler                                          [log in to unmask]
                                     http://www.allegro.com/sieler.html