Prev: Testing a package's internal details.
Next: Having a problem building with win32ada
From: deadlyhead on 5 Mar 2010 01:34
I've been trying to determine if there is any significant performance
difference between two functionally equivalent pieces of code. I've
done the standard thing and, using the Ada.Real_Time package, I'm
saving the time when the code starts, then the time when the code
ends, then examining the difference between them after the code runs.

The problem I'm having, though, is that the timing just isn't
happening. This code will run for 15 seconds and when I examine the
time span, it tells me that no time passed.

Here's my actual code

----------------------------------------------------------------------

-- A test of the cost of conditionals

with Ada.Text_IO; use Ada.Text_IO;
with Ada.Real_Time; use Ada.Real_Time;
procedure Conditional_Test is

Test_Dur : constant := 100_000;

-- We require the input/output for Duration
package Duration_IO is new Fixed_IO (Duration);
use Duration_IO;


Start_Time : Time;
End_Time : Time;
Is_Even : Boolean;
Is_Odd : Boolean;
Junk : Positive;
Junk_In : Natural := 0;

begin -- Conditional_test

Put_Line ("---Starting per-branch assignment test---");

Start_Time := Clock;
for I in 1 .. Test_Dur loop
if I rem 2 = 1 then
Is_Odd := True;
else
Is_Even := True;
end if;

if Is_Even then
for J in reverse 1 .. Test_Dur loop
Junk_In := Junk_In + 1;
end loop;
Junk := I;
elsif Is_Odd then
for J in reverse 1 .. Test_Dur loop
Junk_In := Junk_In + 1;
end loop;
Junk := I;
end if;

Is_Even := False;
Is_Odd := False;
end loop;
End_Time := Clock;

Put ("Assignment within each branch took ");
Put (To_Duration (End_Time - Start_Time), 1, 12, 0);
New_Line (2);


Put_Line ("---Starting combined-branch assignment test---");

Start_Time := Clock;
for I in 1 .. Test_Dur loop
if I rem 2 = 1 then
Is_Odd := True;
else
Is_Even := True;
end if;

if Is_Even then
for J in reverse 1 .. Test_Dur loop
Junk_In := Junk_In + 1;
end loop;
elsif Is_Odd then
for J in reverse 1 .. Test_Dur loop
Junk_In := Junk_In + 1;
end loop;
end if;

if Is_Even or Is_Odd then
Junk := I;
end if;

Is_Even := False;
Is_Odd := False;
end loop;
End_Time := Clock;

Put ("Assignment outside of the branching took ");
Put (To_Duration (End_Time - Start_Time), 1, 12, 0);
New_Line (2);

end Conditional_Test;

----------------------------------------------------------------------

The output of this code is as follows:


---Starting per-branch assignment test---
Assignment within each branch took 0.000000000000

---Starting combined-branch assignment test---
Assignment outside of the branching took 0.000000000000


Why wouldn't any time passage be registered?

I know the code above is convoluted, but I've been trying to find a
way to get _some_ timing to happen. I originally ran a test with delay
statements instead of multiple loops, and the timing worked then, but
I felt that there was a real possibility that the delay statements
could be introducing inaccuracies into the timing, with the overhead
of switching processes in the OS and there being no guarantee of
consistently resuming the code. (Ada does not guarantee that code will
resume exactly delay_time from now, it guarantees that the code will
sleep for _at least_ delay_time.)

Anyway, if I'm missing something here, I'd like to know it. I've read
section D.8 of the ARM several times and I'm just about convinced that
something's broken in my compilers (I'm using GNAT on windows, both
the AdaCore binary and a cygwin binary, both with the same output). Is
there something that I'm missing, like the real-time clock doesn't
advance unless the program delays at some point?

I appreciate any insight. This is baffling me.
From: Dmitry A. Kazakov on 5 Mar 2010 02:55
On Thu, 4 Mar 2010 22:34:47 -0800 (PST), deadlyhead wrote:

> I've been trying to determine if there is any significant performance
> difference between two functionally equivalent pieces of code. I've
> done the standard thing and, using the Ada.Real_Time package, I'm
> saving the time when the code starts, then the time when the code
> ends, then examining the difference between them after the code runs.
>
> The problem I'm having, though, is that the timing just isn't
> happening. This code will run for 15 seconds and when I examine the
> time span, it tells me that no time passed.
>
> Here's my actual code

This is an ancient bug, which managed to survive a number of GNAT compiler
versions.

As a workaround, add delay 0.0 at the beginning of your program:

> ----------------------------------------------------------------------
>
> -- A test of the cost of conditionals
>
> with Ada.Text_IO; use Ada.Text_IO;
> with Ada.Real_Time; use Ada.Real_Time;
> procedure Conditional_Test is
>
> Test_Dur : constant := 100_000;

Test_Dur : constant := 10_000; -- 100_000 overflows on a 32-bit machine

> -- We require the input/output for Duration
> package Duration_IO is new Fixed_IO (Duration);
> use Duration_IO;
>
>
> Start_Time : Time;
> End_Time : Time;
> Is_Even : Boolean;
> Is_Odd : Boolean;
> Junk : Positive;
> Junk_In : Natural := 0;
>
> begin -- Conditional_test

delay 0.0; -- Wake up that dozing Ada RTL!

> Put_Line ("---Starting per-branch assignment test---");
>
> Start_Time := Clock;
> for I in 1 .. Test_Dur loop
> if I rem 2 = 1 then
> Is_Odd := True;
> else
> Is_Even := True;
> end if;
>
> if Is_Even then
> for J in reverse 1 .. Test_Dur loop
> Junk_In := Junk_In + 1;
> end loop;
> Junk := I;
> elsif Is_Odd then
> for J in reverse 1 .. Test_Dur loop
> Junk_In := Junk_In + 1;
> end loop;
> Junk := I;
> end if;
>
> Is_Even := False;
> Is_Odd := False;
> end loop;
> End_Time := Clock;
>
> Put ("Assignment within each branch took ");
> Put (To_Duration (End_Time - Start_Time), 1, 12, 0);
> New_Line (2);
>
>
> Put_Line ("---Starting combined-branch assignment test---");
>
> Start_Time := Clock;
> for I in 1 .. Test_Dur loop
> if I rem 2 = 1 then
> Is_Odd := True;
> else
> Is_Even := True;
> end if;
>
> if Is_Even then
> for J in reverse 1 .. Test_Dur loop
> Junk_In := Junk_In + 1;
> end loop;
> elsif Is_Odd then
> for J in reverse 1 .. Test_Dur loop
> Junk_In := Junk_In + 1;
> end loop;
> end if;
>
> if Is_Even or Is_Odd then
> Junk := I;
> end if;
>
> Is_Even := False;
> Is_Odd := False;
> end loop;
> End_Time := Clock;
>
> Put ("Assignment outside of the branching took ");
> Put (To_Duration (End_Time - Start_Time), 1, 12, 0);
> New_Line (2);
>
> end Conditional_Test;

--
Regards,
Dmitry A. Kazakov
http://www.dmitry-kazakov.de
From: deadlyhead on 5 Mar 2010 03:16
On Mar 4, 11:55 pm, "Dmitry A. Kazakov" <mail...(a)dmitry-kazakov.de>
wrote:
>
> This is an ancient bug, which managed to survive a number of GNAT compiler
> versions.
>
> As a workaround, add delay 0.0 at the beginning of your program:
>
> > ----------------------------------------------------------------------
>
> > --  A test of the cost of conditionals
>
> > with Ada.Text_IO;  use Ada.Text_IO;
> > with Ada.Real_Time; use Ada.Real_Time;
> > procedure Conditional_Test is
>

Exactly what was needed. Thank you!

Do you happen to know if this bug has been fixed in the current
development branch? (At home I compile GNAT based on GCC 4.4, but
haven't done any real-time tests with it yet.) This seems like an
unfortunate bug to have lying around in an otherwise respected
compiler. The ease of the workaround, and likewise that it seems so
pointless to have to insert a dummy delay statement, would lead many
to believe that this bug was just a sloppy error, even if the real
reasons it exists are somewhat more complex.

BTW, my test results with -O3 and -Os, there is no difference in
performance between the two loops, and -Os produces code that is about
33% faster than -O3. With -O0, the second loop is faster by an
average of 10%. I would have thought the extra conditional would have
been costlier.

Again, thanks for the reply!
-- deadlyhead
From: Niklas Holsti on 5 Mar 2010 03:21
deadlyhead wrote:
> I've been trying to determine if there is any significant performance
> difference between two functionally equivalent pieces of code. I've
> done the standard thing and, using the Ada.Real_Time package, I'm
> saving the time when the code starts, then the time when the code
> ends, then examining the difference between them after the code runs.
>
> The problem I'm having, though, is that the timing just isn't
> happening. This code will run for 15 seconds and when I examine the
> time span, it tells me that no time passed.
>
> Here's my actual code

[ code elided ]

Dmitry's already answered your main question. But your code also ha some
other issues that I would like point out, in a friendly spirit. I have
tried your code on Debian Lenny with the Debian GNAT compiler.

Firstly, if I compile with my normal options, -g -O2 -gnato
-fstack-check, the code fails after some seconds with Constraint_Error
due to overflow in the assignment Junk_In := Junk_In + 1 on line 42
(counting the line with all '-' as line 1). This is expected, since this
statement would be executed about (10**10)/2 times, leading to overflow
with a 32-bit Natural counter.

Secondly, if I compile without overflow checks (-g -O2) the program runs
very quickly and displays

---Starting per-branch assignment test---
Assignment within each branch took 0.000006000000

---Starting combined-branch assignment test---
Assignment outside of the branching took 0.000002000000

I believe that GNAT optimizes out almost everything in your loops,
because the results are not used in the program. To disable some of this
optimization you can use pragma Volatile to force GNAT to generate code
that actually executes all the accesses to the variables, for example
like this:

Is_Even : Boolean; pragma Volatile (Is_Even);
Is_Odd : Boolean; pragma Volatile (Is_Odd);
Junk : Positive; pragma Volatile (Junk);
Junk_In : Natural := 0; pragma Volatile (Junk_In);

With this change, and compiling with "-g -O2", the code takes about 1
minute 30 seconds to run on my laptop and displays:

---Starting per-branch assignment test---
Assignment within each branch took 44.178160000000

---Starting combined-branch assignment test---
Assignment outside of the branching took 45.378627000000

I don't think you are not going to find valid performance differences
between different styles of code using this kind of artificial test
programs, because the compiler's code generation and optimization make
such profound changes to the code, depending on the surroundings, data
types, etc.

If you have a real performance problem in a real application, I suggest
that you experiment with changes to the real application code. Use a
profiler to find out where the time is spent and focus on that code.

HTH,

--
Niklas Holsti
Tidorum Ltd
niklas holsti tidorum fi
. @ .
From: Ludovic Brenta on 5 Mar 2010 03:33
Dmitry A. Kazakov wrote on comp.lang.ada:
> On Thu, 4 Mar 2010 22:34:47 -0800 (PST), deadlyhead wrote:
>> The problem I'm having, though, is that the timing just isn't
>> happening.  This code will run for 15 seconds and when I examine the
>> time span, it tells me that no time passed.
>
> This is an ancient bug, which managed to survive a number of GNAT compiler
> versions.
>
> As a workaround, add delay 0.0 at the beginning of your program:
[...]
> delay 0.0; -- Wake up that dozing Ada RTL!

I was not aware of this bug; is there a PR in Bugzilla for it? I don't
see one. Perhaps that might explain how this bug survived several
versions of GNAT?

--
Ludovic Brenta.
 |  Next  |  Last
Pages: 1 2 3 4
Prev: Testing a package's internal details.
Next: Having a problem building with win32ada