ADA code execution times

ADA code execution times

[Brian Franklin]

I asked this question before and received some replies which were of
some use but no answers. So I'll ask again...

What code can I use in my ADA program to report the time. I want to
get an estimate of the execution time.  Getting  the CPU time seems
somewhat complicated so I'll settle for getting the time at the start
and finish of the process in order to get an estimate of the
performance of the code.

OS:    Windows 95
Compiler:   GNAT
Processor:   Pentium

Re: ADA code execution times

[Tom Moran]

>What code can I use in my ADA program
Since my ISP seems to have lost my previous post, here it is again:

with Ada.Calendar,
       Ada.Text_IO;
...
use type Ada.Calendar.Time;
Start : Ada.Calendar.Time;
Elapsed : Duration;
...
Start := Ada.Calendar.Clock;
-- something you want to time
Elapsed ::= Ada.Calendar.Clock - Start;
Ada.Text_IO.Put_Line("It took " & Duration'image(Elapsed) 
   & " seconds");

Last time I checked Duration had a delta in the nanoseconds for Gnat,
although it only used the Win95 timer that ticks every 55
milliseconds.  So if "--something you want to time" takes under 55 ms,
the clock will tick 0 or 1 times and you'll get either 0.0 or 0.055 as
the elapsed time.  If it takes, say, 10 seconds, then you'll get
either 10.0 or 10.055 as the printed value.  Since Win95 rears its
head up and does lengthy things like updating the disk at times of its
own choosing, you should take any short duration with a large grain of
salt.  You can of course do the timing multiple times and take the
average.

Re: ADA code execution times

[Steve Doiel]

Brian Franklin wrote in message <35c354e5.140587456@news.gatech.edu>...
>I asked this question before and received some replies which were of
>some use but no answers. So I'll ask again...
>
>What code can I use in my ADA program to report the time. I want to
>get an estimate of the execution time.  Getting  the CPU time seems
>somewhat complicated so I'll settle for getting the time at the start
>and finish of the process in order to get an estimate of the
>performance of the code.

Here is some code I used to compare the time of using a task versus a
protected type to implement a semaphore.  My basic technique is to capture
the time before performing the thing I want to time, perform the operation
multiple times, and then capture the time at the end .

Right, wrong, or indifferent I figure that timing for one iteration would
introduce too much error due to the low resolution available on the PC's
clock, so timing a bunch of iterations reduces the error.

You're question about timing is somewhat vague.  Is this what you're looking
for?

If not, maybe you're looking for a profiler?  I guess my ESP level isn't
that high.

SteveD

Sample Code:

with ada;
 use ada;
with Text_Io;
with Ada.Float_Text_Io;
with Ada.Integer_Text_Io;
with Ada.Real_Time;
procedure Timing is
  use type Real_Time.time;
  use type Real_Time.time_span;
  protected type TSemaphore is
    entry Take;
    procedure Give;
    entry WaitBlocked;
    private
      isBlocked : BOOLEAN := FALSE;
  end TSemaphore;
  protected body TSemaphore is
    entry Take when NOT isBlocked is
    begin
      isBlocked := TRUE;
    end Take;
    procedure Give is
    begin
      isBlocked := FALSE;
    end Give;
    entry WaitBlocked when isBlocked is
    begin
      null;
    end WaitBlocked;
  end TSemaphore;
  task type TTaskSem is
    entry Take;
    entry Give;
  end TTaskSem;
  task body TTaskSem is
    isBlocked : BOOLEAN := FALSE;
  begin
    loop
      select
        when not isBlocked =>
        accept Take do
          isBlocked := TRUE;
        end Take;
      or
        accept Give do
          isBlocked := FALSE;
        end Give;
      end select;
    end loop;
  end TTaskSem;
  startTime : Real_Time.Time;
  endTime : Real_Time.Time;
  tareTime : Real_Time.Time_Span;
  timeInSeconds : float;
  iterations : constant := 100_000;
  sem : TSemaphore;
  taskSem : TTaskSem;
  task flusher is
  end;
  task body flusher is
  begin
    loop
      sem.WaitBlocked;
      sem.Give;
    end loop;
  end flusher;
begin
  Text_Io.Put_Line( "Started" );
  startTime := Real_Time.Clock;
  for ii in 1..iterations loop
    null;
  end loop;
  endTime := Real_Time.Clock;
  Text_Io.Put( "Time for " );
  Integer_Text_Io.Put( iterations, 1 );
  Text_Io.Put( " iterations of empty loop is " );
  timeInSeconds := Float((endTime - startTime)/Real_Time.Milliseconds(1))*
0.001;
  Float_Text_Io.Put( timeInSeconds, 3, 3, 0 );
  Text_Io.Put_Line( " msec" );
  startTime := Real_Time.Clock;
  for ii in 1..iterations loop
    sem.Take;
--    sem.Give;
  end loop;
  endTime := Real_Time.Clock;
  Text_Io.Put( "Time for " );
  Integer_Text_Io.Put( iterations, 1 );
  Text_Io.Put( " iterations of protected take/give loop is " );
  timeInSeconds := Float((endTime - startTime)/Real_Time.Milliseconds(1))*
0.001;
  Float_Text_Io.Put( timeInSeconds, 3, 3, 0 );
  Text_Io.Put_Line( " msec" );
  startTime := Real_Time.Clock;
  for ii in 1..iterations loop
    taskSem.Take;
    taskSem.Give;
  end loop;
  endTime := Real_Time.Clock;
  Text_Io.Put( "Time for " );
  Integer_Text_Io.Put( iterations, 1 );
  Text_Io.Put( " iterations of task take/give loop is " );
  timeInSeconds := Float((endTime - startTime)/Real_Time.Milliseconds(1))*
0.001;
  Float_Text_Io.Put( timeInSeconds, 3, 3, 0 );
  Text_Io.Put_Line( " msec" );
  abort taskSem;
  abort flusher;
  Text_Io.Put_Line( "Complete!" );
end Timing;

Re: ADA code execution times

[Jerry van Dijk]

Brian Franklin (bf14@prism.gatech.edu) wrote:

: I asked this question before and received some replies which were of
: some use but no answers. So I'll ask again...

Well, actually you did get the answers.

: What code can I use in my ADA program to report the time.

: OS:    Windows 95
: Compiler:   GNAT
: Processor:   Pentium

To anser again:

In the Win32 enviroment there is, to my knowledge, no way to get
more accurate timing than about 1/10th of a second without using
a realtime kernel.

You said you needed millisecond accuracy.

As Tom already said, the QueryPerformance* functions are probably
the most accurate. However, try to run the test program below
several times, and see for yourself how accurate the results are.

-- test.adb
with Win_Timer;
with Ada.Text_IO;

procedure Test is
   Start, Stop : Long_Long_Integer;
begin
   Start := Win_Timer.Get_Current_Count;
   delay 1.234;
   Stop := Win_Timer.Get_Current_Count;
   Ada.Text_IO.Put_Line ("Start:" & Start'Img);
   Ada.Text_IO.Put_Line ("Stop: " & Stop'Img);
   Ada.Text_IO.Put_Line ("Time: " & Integer'Image (Win_Timer.Get_Time (Start, Stop)));
end Test;

-- win_timer.ads
package Win_Timer is

   function Get_Current_Count return Long_Long_Integer;
   -- get current count

   function Get_Time (T1, T2 : Long_Long_Integer) return Integer;
   -- get time difference between T1 and T2 in milliseconds

   No_Counter_Error    : exception;
   Counter_Read_Error  : exception;
   Invalid_Count_Error : exception;

private

   pragma Inline (Get_Time);
   pragma Inline (Get_Current_Count);

end Win_Timer;

-- win_timer.adb
package body Win_Timer is

   type Long_Long_Pointer is access all Long_Long_Integer;
   -- pointer to 64-bit integer

   Temp_Value : aliased Long_Long_Integer;
   -- 64-bit integer buffer

   Frequency : aliased Long_Long_Integer;
   -- counter frequency

   Frequency_Pointer : Long_Long_Pointer := Frequency'Access;
   -- pointer to counter frequency

   ---------------------
   -- Win32 interface --
   ---------------------
   function QueryPerformanceCounter (Count : in Long_Long_Pointer) return Integer;
   pragma Import (StdCall, QueryPerformanceCounter, "QueryPerformanceCounter");

   function QueryPerformanceFrequency (Frequency : in Long_Long_Pointer) return Integer;
   pragma Import (StdCall, QueryPerformanceFrequency, "QueryPerformanceFrequency");

   -----------------------
   -- get current count --
   -----------------------
   function Get_Current_Count return Long_Long_Integer is
      Value : Long_Long_Pointer := Temp_Value'Access;
   begin
      if QueryPerformanceCounter (Value) = 0 then
         raise Counter_Read_Error;
      end if;
      return Value.all;
   end Get_Current_Count;

   -----------------------------------------------------------
   -- get time difference between T1 and T2 in milliseconds --
   -----------------------------------------------------------
   function Get_Time (T1, T2 : Long_Long_Integer) return Integer is
      Dif : Long_Long_Integer := T2 - T1;
   begin
      if T1 > T2 then
         raise Invalid_Count_Error;
      end if;
      return Integer ((1_000 * Dif) / Frequency);
   end;

---------------------------
-- get counter frequency --
---------------------------
begin
   if QueryPerformanceFrequency (Frequency_Pointer) = 0 then
      raise No_Counter_Error;
   end if;
end Win_Timer;

-- 
-- Jerry van Dijk  | email: jdijk@acm.org
-- Leiden, Holland | member Team-Ada
-- Ada & Win32: http://stad.dsl.nl/~jvandyk

Re: ADA code execution times

[dennison]

In article <35c4e297.0@news.pacifier.com>,
  "Steve Doiel" <nospam_steved@pacifier.com> wrote:
>
> Brian Franklin wrote in message <35c354e5.140587456@news.gatech.edu>...
> >I asked this question before and received some replies which were of
> >some use but no answers. So I'll ask again...
> >
> >What code can I use in my ADA program to report the time. I want to
> >get an estimate of the execution time.  Getting  the CPU time seems
> >somewhat complicated so I'll settle for getting the time at the start
> >and finish of the process in order to get an estimate of the
> >performance of the code.
>
> Here is some code I used to compare the time of using a task versus a
> protected type to implement a semaphore.  My basic technique is to capture
> the time before performing the thing I want to time, perform the operation
> multiple times, and then capture the time at the end .


You have to be somewhat careful about that approach in general though. An
optimizer is quite likely to find operations that it can pull outside of the
loop and perform only once. An aggressive optimizer might even notice that the
result won't change, and optimize the entire loop down to one iteration!

T.E.D.

-----== Posted via Deja News, The Leader in Internet Discussion ==-----
http://www.dejanews.com/rg_mkgrp.xp   Create Your Own Free Member Forum