TIMER command

  • This site uses cookies. By continuing to use this site, you are agreeing to our use of cookies. Learn more.
#1
This snippet looks pretty good. TIMER reports reasonable numbers.
Code:
v:\> do forever ( timer & echo %@ping[www.syr.edu,5] & timer )
Timer 1 on: 13:16:46
83
Timer 1 off: 13:16:46  Elapsed: 0:00:00.09
Timer 1 on: 13:16:46
85
Timer 1 off: 13:16:46  Elapsed: 0:00:00.08
Timer 1 on: 13:16:46
84
Timer 1 off: 13:16:46  Elapsed: 0:00:00.10
Timer 1 on: 13:16:46
-1
Timer 1 off: 13:16:51  Elapsed: 0:00:05.00
Timer 1 on: 13:16:51
83
Timer 1 off: 13:16:52  Elapsed: 0:00:00.08
But when I use the shortened version of the TIMER command, I get unreasonable numbers; they're all too small, especially the one after a 5 second timeout.
Code:
do forever ( timer echo %@ping[www.syr.edu,5] )
Timer 1 on: 13:17:30
86
Timer 1 off: 13:17:30  Elapsed: 0:00:00.01
Timer 1 on: 13:17:30
85
Timer 1 off: 13:17:30  Elapsed: 0:00:00.00
Timer 1 on: 13:17:35
-1
Timer 1 off: 13:17:35  Elapsed: 0:00:00.00   <== I watched it wait for 5 seconds
Timer 1 on: 13:17:35
84
Timer 1 off: 13:17:35  Elapsed: 0:00:00.00
 

rconn

Administrator
Staff member
May 14, 2008
10,210
86
#2
But when I use the shortened version of the TIMER command, I get unreasonable numbers; they're all too small, especially the one after a 5 second timeout.
Leaving aside the question of exactly why you would want to time an already timed command ...

This doesn't have anything to do with DO, or even TIMER. @PING is resetting the timer.
 
#5
W
Leaving aside the question of exactly why you would want to time an already timed command ...

This doesn't have anything to do with DO, or even TIMER. @PING is resetting the timer.
Why then does the longer construct
Code:
do forever ( timer & echo %@ping[www.syr.edu,5] & timer )
get it right?

And (re Rex's reply to Steve), I see the same problem with the short version of TIMER when I use my plugin @ICMP or my plugin @CONNECT (TCP by port) instead of @PING. I assure you they do nothing with the system clock. @CONNECT simply calls QueryPerformanceCounter() twice and @ICMP simply reads ICMP_ECHO_REPLY::RoundTripTime.
 
#6
OK. I see what's going on and it seems right. In my original example,
Code:
do forever ( timer echo %@ping[www.syr.edu,5] )
@PING is evaluated when the command line is parsed. Even if that results in a timeout, the command turns into
Code:
timer echo -1
which happens very fast. It was my fault for thinking TIMER (short version) would postpone evaluating variables on it's command line.
Code:
timer echo %%ping[www.syr.edu,5]
works as I would expect.
 
#7
No, Vince - just look at the lines displayed by ECHO in your OP - each ping-time is different from previous and subsequent ones, cannot be from a single evaluation on the first pass. In fact I think the command group itself is probably not fully parsed until it is actually executed (and at least partially reparsed for each execution).

I suspect the actual issue is a race condition between multiple timers, the ones in the code for the @PING function (at least two: one for measuring, and one for timeout) and the one used by the TIMER command.

Rex: users do not care whether an erroneous report came from TCC or from Windows (or any other source). If a certain combination of TCC internal features does not provide dependable results, users blame TCC, even as I (who should have known better) did when I wrote a TCC batch program with a race condition, until I found my own mistake. So maybe all timing features ought to have a warning about race conditions. If we dealt with a programming language intended only for professional programmers, such a C/C++/Fortran/etc., they would be expected to know about race conditions and how to avoid them, but scripting languages are intended for the non-professionals (or worse, the quasiprofessionals) who may have never heard of the phenomenon, so it would promote TCMD's acceptance to include appropriate warnings.
 
#8
I'm not sure about that. Think of it:
Code:
do forever ( timer echo %@ping[...] )
DO looks at its command (timer echo %@ping[...]). The command is parsed, variables evaluated ... ( timer echo -1 ); that took 5 seconds. The command is then executed (very fast) and TIMER reports 0.
Then DO does it again; @ping is re-evaluated, but before the TIMER command is executed.
You can leave DO out of the discussion. It's a matter of when @ping[] is evaluated:
Code:
v:\> timer echo %@ping[128.230.13.42,5]
Timer 1 on: 12:57:37
-1
Timer 1 off: 12:57:37  Elapsed: 0:00:00.00  ("timer echo -1" was executed)

v:\> timer echo %%@ping[128.230.13.42,5]
Timer 1 on: 12:57:44
-1
Timer 1 off: 12:57:49  Elapsed: 0:00:05.01
I think I've got it right. Am I still missing something?
 
#9
Your conjecture may be right, Vince, that @PING is actually executed before TIMER is started. I tried a command, COPY of a 590MB file, instead of the function @PING; the report was reasonable. (2 min 58s). I am not sure there is any interference from @PING with the timer. I need to leave, but you might try using the PING command (I know it is external) instead of @PING; you might also try the DELAY command, which does use TCC and WinAPI to achieve delays, to see what's reported.