Delay-Wait-Sleep tricks.

[foxidrive]

The result below is from an XP VM and the log edited to show the results more clearly.

Code: Select all

@echo off
for %%a in (600 650 700 750 800 850 900 950 1000 1050 1100 1200 1300 1400 1500 1700 1900 2100 2300 2600 2900 3100) do (
timethis ping -n 1 -w %%a 1.1.1.1 |findstr /i "command elapsed">>log.txt
)
pause

Code: Select all

ping -n 1 -w 600 1.1.1.1    TimeThis :  Elapsed Time :  00:00:01.131
ping -n 1 -w 650 1.1.1.1    TimeThis :  Elapsed Time :  00:00:00.961
ping -n 1 -w 700 1.1.1.1    TimeThis :  Elapsed Time :  00:00:00.991
ping -n 1 -w 750 1.1.1.1    TimeThis :  Elapsed Time :  00:00:00.991
ping -n 1 -w 800 1.1.1.1    TimeThis :  Elapsed Time :  00:00:00.981
ping -n 1 -w 850 1.1.1.1    TimeThis :  Elapsed Time :  00:00:00.991
ping -n 1 -w 900 1.1.1.1    TimeThis :  Elapsed Time :  00:00:00.991
ping -n 1 -w 950 1.1.1.1    TimeThis :  Elapsed Time :  00:00:01.492
ping -n 1 -w 1000 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.482
ping -n 1 -w 1050 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.492
ping -n 1 -w 1100 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.492
ping -n 1 -w 1200 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.492
ping -n 1 -w 1300 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.492
ping -n 1 -w 1400 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.492
ping -n 1 -w 1500 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.992
ping -n 1 -w 1700 1.1.1.1   TimeThis :  Elapsed Time :  00:00:02.002
ping -n 1 -w 1900 1.1.1.1   TimeThis :  Elapsed Time :  00:00:02.002
ping -n 1 -w 2100 1.1.1.1   TimeThis :  Elapsed Time :  00:00:02.493
ping -n 1 -w 2300 1.1.1.1   TimeThis :  Elapsed Time :  00:00:02.493
ping -n 1 -w 2600 1.1.1.1   TimeThis :  Elapsed Time :  00:00:02.994
ping -n 1 -w 2900 1.1.1.1   TimeThis :  Elapsed Time :  00:00:02.994
ping -n 1 -w 3100 1.1.1.1   TimeThis :  Elapsed Time :  00:00:03.495

[einstein1969]

If you look at my reply above, the problem with ping is not that it takes long to start, but that it rounds the wait input to 500ms intervals. At least on Win7 as you and I both found out. It'd be great if someone could verify/disprove that on WinXP, since I'm shocked I've never noticed it before.

Yes, I know that there is a rounding error for a long time. But I always thought it was due to a particular configuration of the network or other...

To remove any doubt and to give further information to aGerman I posted that test on startup process. In my initial request I raised this type of problem.

TODO:

Moreover, one must also take into account the CPU throttling (I'm on a laptop with this option active). Is there anyone who can do the test on a machine that has disabled the CPU throttling ?

This may affect (but I'm not sure) the behavior of the ping and perhaps the variable "% time%".

I already did some testing with the "auto tuning of the window stack tcp disabled", but at the moment I get the same result. But I have to finish these tests.

foxidrive should have confirmed that the problem is also on XP.

Einstein1969

[foxidrive]

foxidrive should have confirmed that the problem is also on XP.

I use Windows 8 though - I booted up XP in a VM to test that.

[Squashman]

I do not want to wait with total consumption of cpu.

Are you saying that the FOR command uses 100% of the cpu when it runs.

Yes. On my machine if i use the "FOR ... rem" the CPU is closed to 100% usage (single core)

you running an old Pentium 1,2 or 3?
I will test it it on my old laptop at home to see what happens. My work computer which is dual core barely gets a 3% spike for those 3 thousanths of a second.

Your code seems to use less cpu but seems to take longer to run.

[aGerman]

I run TimeThis against a few external commands. All of them took approx 70ms to load under my Win7 x86. I remember it consumed 150-250ms on my old XP machine.

To figure out if the rounding problem is PING-specific I also run it against a small C one-liner (that calls the Sleep WinAPI). It seems that Windows is precisely enough since the result was the specified time plus the estimated loading time.

The conclusion is that both the loading time and the consumed CPU usage is depending on the conditions on the currently used computer and the utilization of its resources.

Actually I'm not quite certain why this is of so much interest. I mean we are talking about Windows Batch -- What are you expecting?

Regards
aGerman

[penpen]

On a "native" XP (no virtual machine) on AMD Sempron(tm) Processor, 3000+, 1.81 GHz, 960 MB RAM (+64 MB RAM onboard graphic) the result of the ping is similar to foxidrive's result on a virtual machine:

Code: Select all

ping -n 1 -w 600 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.313
ping -n 1 -w 650 1.1.1.1   TimeThis :  Elapsed Time :  00:00:00.984
ping -n 1 -w 700 1.1.1.1   TimeThis :  Elapsed Time :  00:00:00.953
ping -n 1 -w 750 1.1.1.1   TimeThis :  Elapsed Time :  00:00:00.968
ping -n 1 -w 800 1.1.1.1   TimeThis :  Elapsed Time :  00:00:00.937
ping -n 1 -w 850 1.1.1.1   TimeThis :  Elapsed Time :  00:00:00.953
ping -n 1 -w 900 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.453
ping -n 1 -w 950 1.1.1.1   TimeThis :  Elapsed Time :  00:00:01.453
ping -n 1 -w 1000 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.437
ping -n 1 -w 1050 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.453
ping -n 1 -w 1100 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.453
ping -n 1 -w 1200 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.484
ping -n 1 -w 1300 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.484
ping -n 1 -w 1400 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.984
ping -n 1 -w 1500 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.984
ping -n 1 -w 1700 1.1.1.1  TimeThis :  Elapsed Time :  00:00:01.984
ping -n 1 -w 1900 1.1.1.1  TimeThis :  Elapsed Time :  00:00:02.484
ping -n 1 -w 2100 1.1.1.1  TimeThis :  Elapsed Time :  00:00:02.484
ping -n 1 -w 2300 1.1.1.1  TimeThis :  Elapsed Time :  00:00:02.484
ping -n 1 -w 2600 1.1.1.1  TimeThis :  Elapsed Time :  00:00:02.984
ping -n 1 -w 2900 1.1.1.1  TimeThis :  Elapsed Time :  00:00:03.484
ping -n 1 -w 3100 1.1.1.1  TimeThis :  Elapsed Time :  00:00:03.484

@Squashman
The for loop above uses 60% on my pc, but it tends to use as much as possible: A for loop with 100000 iterations uses 100% CPU for a short time.
Maybe your pc is much faster ond you have to use much more iterations to raise the CPU load to maximum.

(aGerman was faster) I've used a JScript with wait to check the precisition of the task/process scheduler:

Code: Select all

@if (true == false) then /*
   @echo off

   for %%a in (600 650 700 750 800 850 900 950 1000 1050 1100 1200 1300 1400 1500 1700 1900 2100 2300 2600 2900 3100) do (
      timethis %SystemRoot%\system32\cscript.exe //E:JScript "%~f0" "%%a"|findstr /i "command elapsed">>log.txt
   )

   goto :eof
*/
@end
if (WScript.Arguments.Unnamed.Length > 0) WScript.sleep (WScript.Arguments.Unnamed.Item (0));

Stored to "wait.bat" and executed it leads to this results:

Code: Select all

C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 600   TimeThis :  Elapsed Time :  00:00:00.796
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 650   TimeThis :  Elapsed Time :  00:00:00.828
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 700   TimeThis :  Elapsed Time :  00:00:00.890
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 750   TimeThis :  Elapsed Time :  00:00:00.937
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 800   TimeThis :  Elapsed Time :  00:00:01.000
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 850   TimeThis :  Elapsed Time :  00:00:01.046
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 900   TimeThis :  Elapsed Time :  00:00:01.093
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 950   TimeThis :  Elapsed Time :  00:00:01.125
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1000  TimeThis :  Elapsed Time :  00:00:01.171
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1050  TimeThis :  Elapsed Time :  00:00:01.234
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1100  TimeThis :  Elapsed Time :  00:00:01.296
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1200  TimeThis :  Elapsed Time :  00:00:01.406
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1300  TimeThis :  Elapsed Time :  00:00:01.515
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1400  TimeThis :  Elapsed Time :  00:00:01.625
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1500  TimeThis :  Elapsed Time :  00:00:01.750
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1700  TimeThis :  Elapsed Time :  00:00:01.875
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 1900  TimeThis :  Elapsed Time :  00:00:02.109
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 2100  TimeThis :  Elapsed Time :  00:00:02.296
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 2300  TimeThis :  Elapsed Time :  00:00:02.500
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 2600  TimeThis :  Elapsed Time :  00:00:02.859
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 2900  TimeThis :  Elapsed Time :  00:00:03.109
C:\WINDOWS\system32\cscript.exe //E:JScript Z:\wait.bat 3100  TimeThis :  Elapsed Time :  00:00:03.281

penpen

[Magialisk]

Batch or otherwise, all I was expecting is for the command to act as its help file indicates:

-w Timeout : Specifies the amount of time, in milliseconds, to wait for the Echo Reply message that corresponds to a given Echo Request message to be received. If the Echo Reply message is not received within the time-out, the "Request timed out" error message is displayed. The default time-out is 4000 (4 seconds).

As is, it treats any value less than 1000ms as 500ms, and any other value rounded down to the nearest multiple of 500ms. It "gives up early" rather than waiting the specified duration for an Echo. An extra sentence in the help to highlight such an obvious impairment is too much to ask?

As two people have now proven it's not a limitation of the task scheduler or the cmd environment, it's just something artificial and undocumented in the ping code.

You could argue ping wasn't designed for sleeping a batch file (it wasn't? ), but even for it's intended use this is broken. If I'm testing a laggy network (or simulating a laggy network) and need to know how many echo replies take longer than 800ms to arrive, I'm going to get a lot of false positives that came between 501ms and 799ms...

[aGerman]

As jeb mentioned several times the developers must have been stoned when they wrote the source of CMD and other command line tools. One bug more or less ...

Regards
aGerman

[einstein1969]

you running an old Pentium 1,2 or 3?
I will test it it on my old laptop at home to see what happens. My work computer which is dual core barely gets a 3% spike for those 3 thousanths of a second.

Your code seems to use less cpu but seems to take longer to run.

I current run on "AMD Turion(tm) 64 Mobile Technology MK-36 @MAX 2000Mhz"

Measure the peak usage of 3 hundredths of a second compared to a second is a typical error.

The delta T of reference of a second is arbitrary.

It is as if you were using the feature only once per second.

But it is not so in my case or in the general case. I want to use the function multiple times in a second and then the calculation to be done is different.

To make a precise calculation should calculate the cpu usage in just 3 cents of use. That is of delta T = 0.03 sec.

You'll see that you are 100% on a single core. On a multi-core you will have the whole divided by the number of cores.

Einstein1969

[penpen]

You could argue ping wasn't designed for sleeping a batch file (it wasn't? ), but even for it's intended use this is broken. If I'm testing a laggy network (or simulating a laggy network) and need to know how many echo replies take longer than 800ms to arrive, I'm going to get a lot of false positives that came between 501ms and 799ms...

I have tested if the ping command waits for the time specified using the option w.

My test environment setup:
2 pcs A and B with fixed IP addresses (192.168.0.10, 192.168.0.11).
B is defined as a gateway of A.
B just sends a ICMP_ECHO_REPLY on every packet it receives after a hardcoded delay: I've used 600ms to 1000ms in 50ms steps. (I wanted to keep it simple.)
I then have used "ping -n 1 -w 800 1.1.1.1" on A.

It may be astounding, but i got no false positives.
So it seems, that "ping.exe" indeed waits the time specified by option w.

So the curious timing must be caused by something different within the ping program (actually i have no idea what may cause it).

penpen

[Squashman]

I want to use the function multiple times in a second

Why?? That doesn't seem to make sense. I would like to know a real world example of where you would call this function multiple times within a second. I see no practical purpose of calling a delay function multiple times within a second just to delay a program for a few thousandths of a second multiple times in a row. If you need real world performance where you are worried about clock cycles then program in Assembler.

[Squashman]

Actually I'm not quite certain why this is of so much interest. I mean we are talking about Windows Batch -- What are you expecting?

+1

[Squashman]

Penpen,
Love the jscript solution. My wife's I5 Quadcore desktop gets a quick 10% cpu usage jump when I run it. Not really sure how to accurately measure the cpu usage. I just have everything shutdown and execute the bat file and watch the cpu usage. It consistently jumps a good 10% every time I execute it.

[penpen]

Under XP you can use "perfmon.exe" to measure the cpu usage of a batch script via its containing shell:
-start cmd shell
-start perfmon
-create a new ?performance indicator set? (just translated word by word to english: Leistungsindikatorensatz) (the shortcut in my xp is Ctrl+E)
-then add an performance indicator (Ctrl+I on my XP)
-Choose "Process" as a "Data Object", "Processor time(%)" as a "Performance Indicator", then the "Instance" "cmd", "Add" and then "Close"
-after that just execute what you want within the cmd shell:

Code: Select all

Z:\>wait.bat

Z:\>(for /L %a in (1,1,1000000) do rem:)>nul

But the cscript.exe has to be added in the same way, as the cmd shell.
(It only has to be added once: It measures the performance of the first process named "cscript" after the tracked process was shuted down.)
I hope this word by word translating is helpfull, and
i hope when using win vista/7/8 this works too.

I think the 10% peak (15% on my pc) is caused by compiling the JScript, but it suffices for testing .
A compiled version (cpp, c#) should produce nearly no CPU load.

penpen

[Magialisk]

I then have used "ping -n 1 -w 800 1.1.1.1" on A.

I'm sure here you meant to say 192.168.0.11, but BRAVO!

I, like you, am dumbfounded what is causing the weird behavior in timing 'ping' that makes it look like it's rounding off the wait time, when according to your test it appears to not be rounding at all. I'm starting to believe aGerman and jeb, the developers were on some good stuff...