Strange behaviour of delay in Windows XP

Strange behaviour of delay in Windows XP

[michael bode]

Hi,

I've seen a very strange behaviour of the delay statement with GNAT on a
Windows XP machine. This is the code:

with  Ada.Text_Io; use Ada.Text_Io;
with Ada.Calendar; use Ada.Calendar;

procedure Testprog is
   T1, T2 : Time;
   D : Duration;
begin
   D := 1.0;
   T1 := Clock;
   delay D;
   T2 := Clock;
   Put_Line ("Expected delay:" & Duration'Image(D));
   Put_Line ("Actual delay:" & Duration'Image(T2-T1));
end Testprog;

And this is what it prints when run on Linux:

Expected delay: 1.000000000
Actual delay: 1.000321000

But I have a (or rather 2) Dell Vostro MT 220 PC where the actual delay
is about 2.7s instead. Tested with GNAT GPL 2008 and 2009 on XP. Another
almost identical Vostro MT 230 works as expected. And to make it more
interesting when I brought the Vostro 220 from my lab to my office it
worked as expected. Back to the lab I got the 2.7s delay again. Most of
the time. Sometimes I got 1.0xxs. There was no noticeable CPU load
during the tests. Then I booted the machine from a Ubuntu Live CD and
tested with the program compiled under Debian Lenny. It worked as
expected: 1.000xxx seconds delay.

Any ideas or should I call a feng shui master?

Re: Strange behaviour of delay in Windows XP

[Vinzent Hoefler]

On Thu, 07 Oct 2010 23:04:33 +0200, michael bode <m.g.bode@web.de> wrote:

[delay 1.0]
> But I have a (or rather 2) Dell Vostro MT 220 PC where the actual delay
> is about 2.7s instead. Tested with GNAT GPL 2008 and 2009 on XP. Another
> almost identical Vostro MT 230 works as expected. And to make it more
> interesting when I brought the Vostro 220 from my lab to my office it
> worked as expected. Back to the lab I got the 2.7s delay again.

Obviously your lab is very CPU intensive. ;)

> Most of the time. Sometimes I got 1.0xxs. There was no noticeable CPU
> load during the tests.

That's probably the explanation. Firstly, Windows is by no means an RTOS,
secondly GNAT's relative delay implementation uses the Sleep call, which
is quite crude when it comes to clock resolution (15 ms and more).
Add CPU load, disk activity and things and the delay can easily exceed
the "expected" time depending on when Windows decides to return from sleep.

With "delay until" you should get better results. Even adding a task could
help, because with tasking enabled, GNAT uses a different and more precise
implementation AFAIK.


Vinzent.

-- 
There is no signature.

Re: Strange behaviour of delay in Windows XP

[michael bode]

Am 07.10.2010 23:35, schrieb Vinzent Hoefler:

> Obviously your lab is very CPU intensive. ;)

Or has bad feng shui ;-)

>> Most of the time. Sometimes I got 1.0xxs. There was no noticeable CPU
>> load during the tests.
> 
> That's probably the explanation. Firstly, Windows is by no means an RTOS,
> secondly GNAT's relative delay implementation uses the Sleep call, which
> is quite crude when it comes to clock resolution (15 ms and more).
> Add CPU load, disk activity and things and the delay can easily exceed
> the "expected" time depending on when Windows decides to return from sleep.

There was NO load during all the tests. And 2.7s instead of 1.0? These
are relativly current machines with 3GHz Core2Duo CPU.

> With "delay until" you should get better results. Even adding a task could
> help, because with tasking enabled, GNAT uses a different and more precise
> implementation AFAIK.

Good hint, I will try if delay until has different behaviour.

Re: Strange behaviour of delay in Windows XP

[Jeffrey Carter]

On 10/07/2010 02:04 PM, michael bode wrote:
>
> with  Ada.Text_Io; use Ada.Text_Io;
> with Ada.Calendar; use Ada.Calendar;
>
> procedure Testprog is
>     T1, T2 : Time;
>     D : Duration;
> begin
>     D := 1.0;
>     T1 := Clock;
>     delay D;

The relative delay is inherently imprecise; add that to the lousy timing on 
Windows and such results are not as surprising as they should be. Try

delay until T1 + D;

and see if that makes a difference.

-- 
Jeff Carter
"When Roman engineers built a bridge, they had to stand under it
while the first legion marched across. If programmers today
worked under similar ground rules, they might well find
themselves getting much more interested in Ada!"
Robert Dewar
62

Re: Strange behaviour of delay in Windows XP

[Randy Brukardt]

"michael bode" <m.g.bode@web.de> wrote in message 
news:i8lcl2$f0i$1@news.eternal-september.org...
...
> But I have a (or rather 2) Dell Vostro MT 220 PC where the actual delay
> is about 2.7s instead. Tested with GNAT GPL 2008 and 2009 on XP. Another
> almost identical Vostro MT 230 works as expected. And to make it more
> interesting when I brought the Vostro 220 from my lab to my office it
> worked as expected. Back to the lab I got the 2.7s delay again. Most of
> the time. Sometimes I got 1.0xxs. There was no noticeable CPU load
> during the tests. Then I booted the machine from a Ubuntu Live CD and
> tested with the program compiled under Debian Lenny. It worked as
> expected: 1.000xxx seconds delay.
>
> Any ideas or should I call a feng shui master?

I have no ideas about your specific problem, but we found when building Claw 
that delays were quite unreliable on Windows. One compiler insisted on 
delaying a full clock tick (0.1s) even for "delay 0.0;" (used to mean 
"yield"; Ada 2012 will actually have a call named "yield") -- this was a 
disaster as we were using it in the primary message loop (adding 0.1s per 
message slowed apps to a crawl). All were inaccurate to some extent or 
another. All were improved to some extent or another after we filed bug 
reports.

It wouldn't be hard to do something in an implementation of "delay" that 
caused a time explosion in some case or another.

                                  Randy.

Re: Strange behaviour of delay in Windows XP

[michael bode]

Am 08.10.2010 00:37, schrieb Jeffrey Carter:

> The relative delay is inherently imprecise; add that to the lousy timing
> on Windows and such results are not as surprising as they should be. 

I've seen that Windows has a larger error than Linux (<15ms vs. <1ms) in
the cases that I call 'working'. But really: 1.7s timing error in a 1s
delay? Is it *that* bad?

> Try
> 
> delay until T1 + D;
> 
> and see if that makes a difference.

Yepp, I will try that.

Re: Strange behaviour of delay in Windows XP

[michael bode]

Am 08.10.2010 02:15, schrieb Randy Brukardt:

> I have no ideas about your specific problem, but we found when building Claw 
> that delays were quite unreliable on Windows. One compiler insisted on 
> delaying a full clock tick (0.1s) even for "delay 0.0;" (used to mean 
> "yield"; Ada 2012 will actually have a call named "yield") -- this was a 
> disaster as we were using it in the primary message loop (adding 0.1s per 
> message slowed apps to a crawl). All were inaccurate to some extent or 
> another. All were improved to some extent or another after we filed bug 
> reports.

I wouldn't complain about one clock tick or 100ms. But 1700ms is really
too much.

> It wouldn't be hard to do something in an implementation of "delay" that 
> caused a time explosion in some case or another.

Does a relative delay do more than call something like usleep(3) or
whatever is the corresponding Win32 API?

Re: Strange behaviour of delay in Windows XP

[Dmitry A. Kazakov]

On Thu, 07 Oct 2010 23:04:33 +0200, michael bode wrote:

> I've seen a very strange behaviour of the delay statement with GNAT on a
> Windows XP machine. This is the code:
> 
> with  Ada.Text_Io; use Ada.Text_Io;
> with Ada.Calendar; use Ada.Calendar;
> 
> procedure Testprog is
>    T1, T2 : Time;
>    D : Duration;
> begin
>    D := 1.0;
>    T1 := Clock;
>    delay D;
>    T2 := Clock;
>    Put_Line ("Expected delay:" & Duration'Image(D));
>    Put_Line ("Actual delay:" & Duration'Image(T2-T1));
> end Testprog;
> 
> And this is what it prints when run on Linux:
> 
> Expected delay: 1.000000000
> Actual delay: 1.000321000
> 
> But I have a (or rather 2) Dell Vostro MT 220 PC where the actual delay
> is about 2.7s instead.

What happens with this:

with Ada.Text_IO;    use Ada.Text_IO;
with Ada.Calendar;   use Ada.Calendar;
with Win32.Mmsystem; use Win32.Mmsystem;
with Win32.WinBase;  use Win32.WinBase;

procedure Testprog is
   T1, T2 : Time;
   D : Duration;
   use type Win32.BOOL;
begin
   if TIMERR_NOERROR /= timeBeginPeriod (1) then
      raise Program_Error;
   end if;
   if 0 = SetThreadPriority (GetCurrentThread,
THREAD_PRIORITY_TIME_CRITICAL) then
      raise Program_Error;
   end if;
   delay 1.0; -- Let the dust settle down
   D := 1.0;
   T1 := Clock;
   delay D;
   T2 := Clock;
   Put_Line ("Expected delay:" & Duration'Image(D));
   Put_Line ("Actual delay:" & Duration'Image(T2-T1));
end Testprog;

timeBeginPeriod (1) changes the resolution of timer to 1ms. Some older
systems had 10ms by default.

SetThreadPriority changes the priority to R-T.

> Any ideas or should I call a feng shui master?

Turn down indexing service, anti-virus software and whatever mess is
running on the computer in background.

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

Re: Strange behaviour of delay in Windows XP

[michael bode]

Jeffrey Carter schrieb:

> delay until T1 + D;
> 
> and see if that makes a difference.

Doesn't make any difference.

So far this all happens only on 2 Vostro 220/XP Machines with no CPU
load. Other XP machines or even another Vostro 220 with Win7 work nice.
I suspect a special combination of OS, BIOS and CPU to be the culprit.

...

Bingo. A BIOS update did the trick.

Re: Strange behaviour of delay in Windows XP

[Randy Brukardt]

"michael bode" <m.g.bode@web.de> wrote in message 
news:i8mag8$egc$1@news.eternal-september.org...
...
>> It wouldn't be hard to do something in an implementation of "delay" that
>> caused a time explosion in some case or another.
>
> Does a relative delay do more than call something like usleep(3) or
> whatever is the corresponding Win32 API?

I'd expect that to be compiler-specific. I would guess that many compilers 
would turn it into some form of delay until.

But just calling Sleep in the Win32 API is usually where the problems come 
from; you can't just call it it with any old value because it rounds it up 
to 0.1s. So I could imagine an implementation that for whatever reason 
decided to split up the Sleep calls (maybe to poll something else) could get 
in real trouble. In your case, if it chopped the 1.0s into 270 Sleep calls 
for some reason, you'd get the behavior you see. That could happen if the 
programmer(s) wasn't familar with the oddball behavior of Win32 Sleep.

In Janus/Ada, I had to write code to busy-wait if the delay time is less 
than 0.1s; we only call Sleep if the delay time is longer. (That doesn't 
always work right, either, but I'm not quite sure why.)

                                                   Randy.

Re: Strange behaviour of delay in Windows XP

[Dmitry A. Kazakov]

On Sat, 9 Oct 2010 01:42:54 -0500, Randy Brukardt wrote:

> In Janus/Ada, I had to write code to busy-wait if the delay time is less 
> than 0.1s; we only call Sleep if the delay time is longer. (That doesn't 
> always work right, either, but I'm not quite sure why.)

Call timeBeginPeriod (1) somewhere upon elaboration of Claw, and then you
will be able to wait for 1ms. Note that it is not just Sleep, which depends
on this setting, actually all waitable timers and scheduling are. The
effect of timeBeginPeriod is global (I like Windows (:-)), which is not
bad, unless you have some 66MHz i486.

P.S. I think it is 1ms since Windows XP.

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

Re: Strange behaviour of delay in Windows XP

[Yannick Duchêne (Hibou57)]

Le Fri, 08 Oct 2010 02:15:40 +0200, Randy Brukardt <randy@rrsoftware.com>  
a écrit:
> I have no ideas about your specific problem, but we found when building  
> Claw that delays were quite unreliable on Windows. One compiler insisted  
> on
> delaying a full clock tick (0.1s) even for "delay 0.0;" (used to mean
> "yield"; *Ada 2012 will actually have a call named "yield"*)
Ada 2012 has Yield ? Great
Thanks a lot, you all done a very good job :)

-- 
Si les chats miaulent et font autant de vocalises bizarres, c’est pas pour  
les chiens.