TIMER command

[vefatica]

This snippet looks pretty good. TIMER reports reasonable numbers.

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.

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]

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.

 

[Steve Fabian]

This doesn't have anything to do with DO, or even TIMER. @PING is resetting the timer.

Not doumented.Does it reset all 3 timers, or only timer /1 ?

 

[rconn]

Not doumented.Does it reset all 3 timers, or only timer /1 ?

Not documented, because it's not TCC doing it. It resets the system clock momentarily, so it affects everything.

 

[vefatica]

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

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.

 

[vefatica]

OK. I see what's going on and it seems right. In my original example,

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

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.

timer echo %%ping[www.syr.edu,5]

works as I would expect.

 

[Steve Fabian]

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.

 

[vefatica]

I'm not sure about that. Think of it:

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:

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?

 

[Steve Fabian]

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.

 

[vefatica]

Doubling the '%' on @PING seems to work just fine.