Ada.Real_Time behavior with GNAT

Ada.Real_Time behavior with GNAT

[kongra]

Hi everybody.

I have a question related to the Ada.Real_Time package. When I compile
the following code using GNAT GPL 2007 on Windows XP SP2 I observe
some strange looking behavior.

with Ada.Real_Time;
with Ada.Text_IO;

procedure Timing is
   Start_T : Ada.Real_Time.Time;
   End_T   : Ada.Real_Time.Time;
   Total_T : Duration;
   Sleep_T : constant Duration := Duration (0.0001);

   use Ada.Real_Time;

   Val : Integer := 0;
begin
   -- delay Sleep_T;
   Start_T := Ada.Real_Time.Clock;
   for K in 1 .. 10 loop
      for I in 1 .. 10_000_000 loop
         Val := Val + I;
      end loop;
   end loop;
   End_T   := Ada.Real_Time.Clock;
   Total_T := Ada.Real_Time.To_Duration (End_T - Start_T);
   Ada.Text_IO.Put_Line (Integer'Image (Val));
   Ada.Text_IO.Put_Line (Duration'Image (Total_T));
end Timing;

The compilation command is pretty straightforward: gnatmake Timing.adb
-o timing.exe. Running timing.exe I get

1432236160
0.000000000

To my surprise the total time is 0 here, though performing all the
computations takes some observable time. However removing comment in
the line containing statement delay Sleep_T; causes

1432236160
0.431441426

Apparently the total duration seems correct now. I get a similar
change by putting

with Ada.Calendar;

to the compilation unit (without completely using it). Moreover the
delay statement has got the same impact on the program execution even
when it's placed in some procedure other than Timing and the procedure
is not used at all.

I tried the same code in a bigger project using switches like those in
the Ada Wikibooks examples, getting the same.

Can it be explained or is there something I don't know about timing in
Ada ? I'm a beginner in Ada (after 7+ years Java coding) and I think
it's a great programming language, worth to be promoted among
students. But this one really surprised me even if I was able to avoid
using Ada.Calendar (for example prohibited by Ravenscar profile) using
a hack with delay.

Best regards,

Konrad Grzanek.

Re: Ada.Real_Time behavior with GNAT

[george.priv]

On Mar 29, 9:51 am, kongra <kon...@gmail.com> wrote:
> Hi everybody.
>
> I have a question related to the Ada.Real_Time package. When I compile
> the following code using GNAT GPL 2007 on Windows XP SP2 I observe
> some strange looking behavior.
>
> with Ada.Real_Time;
> with Ada.Text_IO;
>
> procedure Timing is
>    Start_T : Ada.Real_Time.Time;
>    End_T   : Ada.Real_Time.Time;
>    Total_T : Duration;
>    Sleep_T : constant Duration := Duration (0.0001);
>
>    use Ada.Real_Time;
>
>    Val : Integer := 0;
> begin
>    -- delay Sleep_T;
>    Start_T := Ada.Real_Time.Clock;
>    for K in 1 .. 10 loop
>       for I in 1 .. 10_000_000 loop
>          Val := Val + I;
>       end loop;
>    end loop;
>    End_T   := Ada.Real_Time.Clock;
>    Total_T := Ada.Real_Time.To_Duration (End_T - Start_T);
>    Ada.Text_IO.Put_Line (Integer'Image (Val));
>    Ada.Text_IO.Put_Line (Duration'Image (Total_T));
> end Timing;
>
> The compilation command is pretty straightforward: gnatmake Timing.adb
> -o timing.exe. Running timing.exe I get
>
> 1432236160
> 0.000000000
>
> To my surprise the total time is 0 here, though performing all the
> computations takes some observable time. However removing comment in
> the line containing statement delay Sleep_T; causes
>
> 1432236160
> 0.431441426
>
> Apparently the total duration seems correct now. I get a similar
> change by putting
>
> with Ada.Calendar;
>
> to the compilation unit (without completely using it). Moreover the
> delay statement has got the same impact on the program execution even
> when it's placed in some procedure other than Timing and the procedure
> is not used at all.
>
> I tried the same code in a bigger project using switches like those in
> the Ada Wikibooks examples, getting the same.
>
> Can it be explained or is there something I don't know about timing in
> Ada ? I'm a beginner in Ada (after 7+ years Java coding) and I think
> it's a great programming language, worth to be promoted among
> students. But this one really surprised me even if I was able to avoid
> using Ada.Calendar (for example prohibited by Ravenscar profile) using
> a hack with delay.
>
> Best regards,
>
> Konrad Grzanek.

Your program should overflow (unless you suppress checks) raising
Constraint_Error for Val. It runs fine on Vista though after fixing
overflow problem

George.

Re: Ada.Real_Time behavior with GNAT

[Georg Bauhaus]

george.priv@gmail.com wrote:

> Your program should overflow (unless you suppress checks) raising
> Constraint_Error for Val. It runs fine on Vista though after fixing
> overflow problem

The overflow fix (+ I <--> + 1 ?), and also running GNAT in Ada
mode (-gnato). Both do not fix the Total_T = 0.0 for me though.
Vista 64bits.

GNATLS GPL 2007 (20070405-41)
Copyright 1997-2007, Free Software Foundation, Inc.

The Debian GNAT compiler produces expected results, though.

GNATLS 4.1.220061115prerelease (Debian 4.1.1-22)
Copyright 1997-2005 Free Software Foundation, Inc.

Re: Ada.Real_Time behavior with GNAT

[george.priv]

On Mar 29, 1:29 pm, Georg Bauhaus <rm.tsoh.plus-
bug.bauh...@maps.futureapps.de> wrote:
> george.p...@gmail.com wrote:
> > Your program should overflow (unless you suppress checks) raising
> > Constraint_Error for Val. It runs fine on Vista though after fixing
> > overflow problem
>
> The overflow fix (+ I <--> + 1 ?), and also running GNAT in Ada
> mode (-gnato). Both do not fix the Total_T = 0.0 for me though.
> Vista 64bits.
>
> GNATLS GPL 2007 (20070405-41)
> Copyright 1997-2007, Free Software Foundation, Inc.
>
> The Debian GNAT compiler produces expected results, though.
>
> GNATLS 4.1.220061115prerelease (Debian 4.1.1-22)
> Copyright 1997-2005 Free Software Foundation, Inc.

Checked again after rebooting and works fine (Vista Ultimate: Version
6.0.6000) Gateway 2000 Tablet.
Takes 4 times longer with range checking (-O2).

C:\Users\gpriv.AXONX\Documents\ada>main
 100000000
 0.101334388

C:\Users\gpriv.AXONX\Documents\ada>main
 100000000
 0.429672137

George.

Re: Ada.Real_Time behavior with GNAT

[Konrad Grzanek]

On 29 Mar, 18:29, Georg Bauhaus <rm.tsoh.plus-
bug.bauh...@maps.futureapps.de> wrote:
> george.p...@gmail.com wrote:
> > Your program should overflow (unless you suppress checks) raising
> > Constraint_Error for Val. It runs fine on Vista though after fixing
> > overflow problem

Right, the way Ada handles overflows is one of the reasons I plan to
migrate most of my future development to it.

>
> The overflow fix (+ I <--> + 1 ?), and also running GNAT in Ada
> mode (-gnato). Both do not fix the Total_T = 0.0 for me though.
> Vista 64bits.
>

I mentioned using another project settings for my test in the initial
posts, and yes, I also can't see any impact of the -gnato compiler
switch on these timing problems.

Re: Ada.Real_Time behavior with GNAT

[Simon Wright]

Works fine with GNAT GPL 2007 on Powerbook. It takes the same time
(more-or-less) whether the initial delay is present or not.

I think it takes marginally longer if the overflow error is present,
not sure why that would be.

The way GNAT approaches Ada.Real_Time differs from platform to
platform -- I'm pretty sure that VxWorks used to use the same
mechanism under the hood, which made for problematic behaviour if the
POSIX time was altered. You may have come across some interaction
between Ada.Real_Time and the elaboration of Ada.Calendar on Windows.

Re: Ada.Real_Time behavior with GNAT

[Dmitry A. Kazakov]

On Sat, 29 Mar 2008 06:51:58 -0700 (PDT), kongra wrote:

> I have a question related to the Ada.Real_Time package.

[...]

> Sleep_T : constant Duration := Duration (0.0001);

You do don't need type conversion here:

   Sleep_T : constant Duration := 0.0001; -- This is OK

[...]

> Can it be explained or is there something I don't know about timing in
> Ada ?

I remotely remember a discussion about this compiler bug  It was discussed
in comp.lang.ada some time ago. I also remember that some people mentioned
tasking problems also circumvented by an initial delay. Which BTW can be
just 0.0;

My explanation is that GNAT RTL is improperly elaborated under Windows.
Fortunately, a delay at the program beginning wakes it up. 

-- 
Regards,
Dmitry A. Kazakov
http://www.dmitry-kazakov.de

Re: Ada.Real_Time behavior with GNAT

[Konrad Grzanek]

>
> My explanation is that GNAT RTL is improperly elaborated under Windows.
> Fortunately, a delay at the program beginning wakes it up.
>

Thanks for such a quick response from all of you. I hope this will be
fixed in some future compiler release. And it's not so much disturbing
after all. I only wanted to confirm my initial suspicions. BTW is
there any registry (FAQ) of such unexpected Ada compiler behaviors ?

Re: Ada.Real_Time behavior with GNAT

[george.priv]

On Mar 29, 3:46 pm, Konrad Grzanek <kon...@gmail.com> wrote:
> > My explanation is that GNAT RTL is improperly elaborated under Windows.
> > Fortunately, a delay at the program beginning wakes it up.
>
> Thanks for such a quick response from all of you. I hope this will be
> fixed in some future compiler release. And it's not so much disturbing
> after all. I only wanted to confirm my initial suspicions. BTW is
> there any registry (FAQ) of such unexpected Ada compiler behaviors ?

It's even more interesting:  My version worked but it is slightly
different from your original in that Timing is enclosed in Main
procedure.  When I put Timing in separate package and it also worked
fine.

When I used your code exact it did show 0 time.  It got to do with
elaboration sequence as was mentioned already.  I think for practical
reasons real-time applications will be multi-package anyways, so I
would not worry about it much.

George.

Re: Ada.Real_Time behavior with GNAT

[Konrad Grzanek]

> It's even more interesting:  My version worked but it is slightly
> different from your original in that Timing is enclosed in Main
> procedure.  When I put Timing in separate package and it also worked
> fine.
>
> When I used your code exact it did show 0 time.  It got to do with
> elaboration sequence as was mentioned already.  I think for practical
> reasons real-time applications will be multi-package anyways, so I
> would not worry about it much.
>

Well, actually I started from somewhat more complicated point. I had
my Main procedure placed in Main.adb and there was also a package
called Sim.Time_Utils where all my timing procedures and types were
defined. So the initial situation was exactly like the one mentioned
by you - RT elements used inside a package body. It wasn't working so
I decided to create the Timing test.

I also tried to enclose Timing in Main like you did. With 0.0000
Total_T. So in my environment it doesn't help.

Re: Ada.Real_Time behavior with GNAT

[Georg Bauhaus]

Konrad Grzanek wrote:
>> My explanation is that GNAT RTL is improperly elaborated under Windows.
>> Fortunately, a delay at the program beginning wakes it up.
>>
> 
> Thanks for such a quick response from all of you. I hope this will be
> fixed in some future compiler release. And it's not so much disturbing
> after all. I only wanted to confirm my initial suspicions. BTW is
> there any registry (FAQ) of such unexpected Ada compiler behaviors ?

The WiKi book has a new subsection,
http://en.wikibooks.org/wiki/Ada_Programming/Tips#Quirks

Semantics of statement reordering relevant to Ada.Real_Time

[Eric Hughes]

On Mar 29, 7:51 am, kongra <kon...@gmail.com> wrote:
>    Start_T := Ada.Real_Time.Clock;
>    for K in 1 .. 10 loop
>       for I in 1 .. 10_000_000 loop
>          Val := Val + I;
>       end loop;
>    end loop;
>    End_T   := Ada.Real_Time.Clock;

I have a question about this piece of the program.  Because the middle
uses only variables 'K', 'I', and 'Val', and the side-effects of
modifying these variables are entirely local, and because there's no
inter-dependency of these variables upon either the first or last
statements, aren't the following reorderings legal for code
generation?  To wit:

    Long_Statement ;
    Start_T := Ada.Real_Time.Clock ;
    End_T   := Ada.Real_Time.Clock ;

    Start_T := Ada.Real_Time.Clock ;
    End_T   := Ada.Real_Time.Clock ;
    Long_Statement ;

Irrelevant to the quirks mentioned earlier, isn't it legal operation
for the interval to come out zero?  It seems that for known-correct
operation for all possible compilers you'd need to manually serialize
these operations in the order desired.

Eric

Re: Semantics of statement reordering relevant to Ada.Real_Time

[Robert A Duff]

Eric Hughes <eric.eh9@gmail.com> writes:

> On Mar 29, 7:51 am, kongra <kon...@gmail.com> wrote:
>>    Start_T := Ada.Real_Time.Clock;
>>    for K in 1 .. 10 loop
>>       for I in 1 .. 10_000_000 loop
>>          Val := Val + I;
>>       end loop;
>>    end loop;
>>    End_T   := Ada.Real_Time.Clock;
>
> I have a question about this piece of the program.  Because the middle
> uses only variables 'K', 'I', and 'Val', and the side-effects of
> modifying these variables are entirely local, and because there's no
> inter-dependency of these variables upon either the first or last
> statements, aren't the following reorderings legal for code
> generation?  To wit:
>
>     Long_Statement ;
>     Start_T := Ada.Real_Time.Clock ;
>     End_T   := Ada.Real_Time.Clock ;
>
>     Start_T := Ada.Real_Time.Clock ;
>     End_T   := Ada.Real_Time.Clock ;
>     Long_Statement ;
>
> Irrelevant to the quirks mentioned earlier, isn't it legal operation
> for the interval to come out zero?

Yes.

For example, I can calculate the final value of Val with pencil and
paper, so I guess I could teach an optimizer to do it at compile time.
;-)

>...It seems that for known-correct
> operation for all possible compilers you'd need to manually serialize
> these operations in the order desired.

The only thing that's guaranteed is I/O behavior, so you have to do some
I/O.  And you should inspect the generated machine code to see if you're
measuring what you think you're measuring.  In other words, this sort of
thing is pretty much outside the language definition.  Also, it might be
better to measure using outside tools, like the Unix 'time' command, or
perhaps a stopwatch.

- Bob

Re: Semantics of statement reordering relevant to Ada.Real_Time

[Eric Hughes]

On Mar 30, 12:59 pm, Robert A Duff <bobd...@shell01.TheWorld.com>
wrote:
> The only thing that's guaranteed is I/O behavior, so you have to do some
> I/O.

Only?  You can also count on task termination, no?  Example code
below.

Eric


with Ada.Real_Time ;
with Ada.Text_IO ;
procedure Foo
is
   Val : Natural := 0 ;
   Start_T, End_T : Ada.Real_Time.Time ;
   use Ada.Real_Time ;
begin
   declare
      task Start_Timer ;
      task body Start_Timer is begin
         Start_T := Ada.Real_Time.Clock ;
      end ;
   begin
      null ;
   end ;

   declare
      task Compute ;
      task body Compute is begin
         for K in 1 .. 10 loop
            for I in 1 .. 10_000 loop
               Val := Val + I * I ;
            end loop;
         end loop;
      end ;
   begin
      null ;
   end ;

   declare
      task End_Timer ;
      task body End_Timer is begin
         End_T := Ada.Real_Time.Clock ;
      end ;
   begin
      null ;
   end ;

   Ada.Text_IO.Put_Line( Natural'Image( Val ) ) ;
   Ada.Text_IO.Put_Line( Duration'Image( To_Duration( End_T -
Start_T ) ) ) ;

end Foo ;

Re: Semantics of statement reordering relevant to Ada.Real_Time

[Robert A Duff]

Eric Hughes <eric.eh9@gmail.com> writes:

> On Mar 30, 12:59 pm, Robert A Duff <bobd...@shell01.TheWorld.com>
> wrote:
>> The only thing that's guaranteed is I/O behavior, so you have to do some
>> I/O.
>
> Only?  You can also count on task termination, no?

Insofar as it affects I/O, yes.  And I suppose you can count on
termination of the program as a whole (that is, if all tasks
terminate, then so should the program).

>...Example code
> below.
>
> Eric
>
>
> with Ada.Real_Time ;
> with Ada.Text_IO ;
> procedure Foo
> is
>    Val : Natural := 0 ;

Better make that modular, or this conversion gets confused by the
overflow issue.  Oh, never mind, I see you reduced the counts,
and (if I can do that in my head correctly) it won't overflow. ;-)

>    Start_T, End_T : Ada.Real_Time.Time ;
>    use Ada.Real_Time ;
> begin
>    declare
>       task Start_Timer ;
>       task body Start_Timer is begin
>          Start_T := Ada.Real_Time.Clock ;
>       end ;
>    begin
>       null ;
>    end ;
>
>    declare
>       task Compute ;
>       task body Compute is begin
>          for K in 1 .. 10 loop
>             for I in 1 .. 10_000 loop
>                Val := Val + I * I ;
>             end loop;
>          end loop;
>       end ;
>    begin
>       null ;
>    end ;
>
>    declare
>       task End_Timer ;
>       task body End_Timer is begin
>          End_T := Ada.Real_Time.Clock ;
>       end ;
>    begin
>       null ;
>    end ;
>
>    Ada.Text_IO.Put_Line( Natural'Image( Val ) ) ;
>    Ada.Text_IO.Put_Line( Duration'Image( To_Duration( End_T -
> Start_T ) ) ) ;
>
> end Foo ;

I don't see any language rule that would prevent moving the calculation
of Val before or after the Start_Timer or End_Timer tasks, since they
don't use that value.  Or in parallel with them.  Or at compile time.

I'm not claiming that real compilers do these transformations
in practise, nor implying that they "should".

I suppose you could reasonably argue that the Clock in Start_Timer must
happen before the one in End_Timer (since a calculation based on those
values is printed out).  So I guess it would be wrong to print
a negative time span.

Meaningful benchmarking is hard!  ;-)

- Bob