Page 5
Timing an Event in DataFlex
by Curtis Krauskopf
Using SYSDATE
for Microsecond Timing
With
some clever tinkering, we now have the tools to be able
to have SYSDATE and SYSDATE4 tell us (indirectly) in
what fraction of a second an event happened. This technique
is so accurate that it is able to tell me, within 40
microseconds (0.000040 seconds), how long an event took.
In
delay.src,
I showed how we could synchronize the start of an event
with the beginning of a second. Since we have the program's
execution synchronized with the system clock, we can
use that to our advantage by incrementing a counter
during an entire second. That will tell us how many
times the counter can be incremented on that hardware
(based on its CPU and the DataFlex runtime that is executing).
Once
we have that information, we can then let the event
that we're really interested in timing happen. When
that finishes, we increment a different counter to count
the amount of time that remained in the second after
the event finished. Subtracting that number from the
number of increments in a whole second will tell us
what fraction of a second the event consumed.
Here's
a diagram of this whole process:
This
diagram shows the following events:
| Second |
Event |
|
:06
|
The
program starts at some fraction of a second after
the system clock rolled over to the sixth second
in the minute. The program immediately enters a
wait loop that repeats until the clock rolls over
to :07. |
|
:07
|
The
program calibrates itself by incrementing an integer
for an entire second. This tells us how many times
an integer can be incremented per second. |
|
:08
|
The
event being measured starts. In this example,
it also stops in the same second, but that's not
necessary. The event could stop in any second
and the rest of this process would remain the
same (and just as accurate).
After
the event stops, we immediately enter a loop that
increments a different integer. The number of
incrementations that are made before the next
second (:09) tells us how much time was left after
the event finished.
|
|
:09
|
At
:09, the loop that increments the second integer
finishes and we can report the results.
|
The
equation to calculate the fraction of a second used
by the event is in equation #1:
| (1) |
|
amount_used =
|
calibration - post_event
calibration |
|
In
equation 1, both calibration and post_event
are the number of integer incrementations completed
in the appropriate phases. calibration is incremented
during an entire second to calibrate the number of integer
increments that can happen per second. post_event
is incremented immediately after the event being timed
has finished. post_event indicates how much time
was left in the second that the event stopped.
As
an example, let's say that the calibration phase incremented
an integer 25,000 times. After the event, let's say
that the second integer (post_event) incremented
4,000 times. The fraction of a second used by the event
is in equation #2:
| (2) |
|
amount_used =
|
25000 - 4000
25000 |
= 0.84 seconds |
|
A
DataFlex program that demonstrates this concept is:
// accurate.src
// by Curtis Krauskopf at www.decompile.com
//
// This program shows how to make SYSDATE4 detect
// fractions of a second. On a 1 Ghz Dell computer
// running DataFlex 3.1d, I'm able to get a
// resolution of 40 microseconds.
//
//
date today
integer hour minute second start
date before after
integer before_hour before_minute before_second
integer after_hour after_minute after_second
integer calibration
integer finish_ticks
// First phase: Initialize all variables
move 0 to calibration
move 0 to finish_ticks
// Second phase: enter a loop that waits until
// the second on the system clock changes.
sysdate4 today hour minute start
repeat
sysdate4 today hour minute second
until start ne second
// Execution and the system clock are now synchronized.
// Enter a loop that increments a counter for an
// entire second.
repeat
sysdate4 before before_hour before_minute before_second
increment calibration
until before_second NE second
// Now that we have calibrated the number of integer
// increments per second, we can test how long our
// event takes:
showln "Press any key to stop the test."
string akey 1
inkey akey
// The event if finished, but we need to record the
// amount of time that is left in this second.
sysdate4 after after_hour after_minute after_second
repeat
sysdate4 today hour minute second
increment finish_ticks
until after_second NE second
// Now we can report how long the event took:
show "Calibration recorded " calibration
showln " increments per second."
showln
show "The event had " finish_ticks
showln " increments before the second changed."
showln
show "The event took "
number before_time // Accumulated number of seconds
number after_time
move (integer(before) * 3600 * 24) to before_time
move (before_time + (before_hour * 3600)) to before_time
move (before_time + (before_minute * 60)) to before_time
move (before_time + (before_second)) to before_time
move (integer(after) * 3600 * 24) to after_time
move (after_time + (after_hour * 3600)) to after_time
move (after_time + (after_minute * 60)) to after_time
move (after_time + (after_second)) to after_time
show (after_time - before_time)
// Fractional numbers converted to strings in DataFlex have
// a leading 0. This block converts the result (a number)
// to a string and then removes the leading "0"
string result
move (number(calibration) - finish_ticks / calibration) to result
replace "0." in result with "."
show result
showln " seconds."
showln
showln
showln "Press any key to continue."
inkey akey
|
The
output for this program looks like this:
On
a Windows system, if you run the program several times
(remember the rules
of thumb when testing event timing on a computer),
you might have noticed something odd. The calibration
value reported in each test run might be different!
Here
are some snapshots of four test runs on my system running
DataFlex 3.1d:
The
problem is that the Windows operating system is stealing
timeslices from the program. If I boot to MS-Dos and
run the same test program, I get calibration results
that are only a few increments from each other.
Copyright
2003 The Database Managers, Inc.
|
