TIMER command

May 20, 2008
9,524
64
Syracuse, NY, USA
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
11,082
99
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.
 
May 20, 2008
9,524
64
Syracuse, NY, USA
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.
 
May 20, 2008
9,524
64
Syracuse, NY, USA
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.
 
May 20, 2008
3,520
3
Elkridge, MD, USA
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.
 
May 20, 2008
9,524
64
Syracuse, NY, USA
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?
 
May 20, 2008
3,520
3
Elkridge, MD, USA
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.