Welcome!

By registering with us, you'll be able to discuss, share and private message with other members of our community.

SignUp Now!

Timing commands with $= in the prompt?

vefatica

vefatica

May
13,399
190
As far as I can tell, the minimum time that can be measured with $= in the prompt is 50 ms. For example

Code: 
v:\> eset prompt
prompt=$= $e[32;1m$p$g$s$e[0m

5.043 v:\> ()

0.050 v:\> noop

0.050

In fact anything measured with $= is 50 ms longer than when measured with TIMER.

I don't know when this started but it is not the case in v20.

Code: 
g:\tc20> ver

TCC  20.11.46   Windows 7 [Version 6.1.7601]

g:\tc20> eset prompt
PROMPT=$= $e[32;1m$p$g$s$e[0m

0:00:04.98 g:\tc20> ()

0:00:00.00 g:\tc20> noop

0:00:00.00 g:\tc20>

Can the behavior be changed so that timing with $= will be more accurate?

Speculation: It's almost as if there's a hard-coded Sleep(50) after the start time of a command is recorded (I see the same thing if I use PRE_EXEC and POST_EXEC to do the timing myself). If that's the case, couldn't 50 ms be subtracted from $='s time (and the result max'd with 0)? If that's not the case, I'm very curious about what's happening.
 
1. There is no Sleep().
2. TCC v20 shows 0 because its timer resolution is much coarser (like 50x).
3. On my system, I see about 0.006 seconds for something like "rem".
4. You apparently believe that executing several thousand lines of code to parse the command line (even if it's only something like "rem") can be done without using any CPU cycles. Would that it were true ...
 
rconn said:
1. There is no Sleep().
2. TCC v20 shows 0 because its timer resolution is much coarser (like 50x).
3. On my system, I see about 0.006 seconds for something like "rem".
4. You apparently believe that executing several thousand lines of code to parse the command line (even if it's only something like "rem") can be done without using any CPU cycles. Would that it were true ...
Click to expand...
Here, REM shows 0.050.
Code: 
v:\> eset prompt
prompt=$= $e[32;1m$p$g$s$e[0m

3.717 v:\> rem

0.050 v:\>

And EVERYTHING takes ~50 ms longer according to $= than according to TIMER.

Code: 
0.050 v:\> timer & (rem) & timer
Timer 1 on: 21:45:12
Timer 1 off: 21:45:12  Elapsed: 0:00:00.001

0.052 v:\>

Code: 
0.050 v:\> timer & do i=1 to 10000 ( rem ) & timer
Timer 1 on: 21:50:58
Timer 1 off: 21:50:59  Elapsed: 0:00:01.427

1.478 v:\>

I see the same ~50 ms if I do the timing like this:

Code: 
v:\> alias pre_exec `timer /10 /q on`

0.000 v:\> set prompt=`%@timer[10]$s$p$g$s`

0:00:00.049 v:\> rem

0:00:00.049 v:\>

50 ms is quite a long time. I know TCC can parse much longer command lines in much less time. And, here, that ~50 ms is pretty constant. Do you have any concrete ideas about what I'm seeing/measuring?
 
It's the History logging! Using $= ...

Code: 
0.000 v:\> rem

0.050 v:\> option //histlogon=no

0.050 v:\> rem

0.001 v:\>

Can the timer for $= be started after the command is logged? ... maybe PRE_EXEC done after the logging also?
 
rconn said:
Not without rewriting the parser (and breaking everything else).
Click to expand...
Oh, well! No big deal. TIMER works well.

My history log was about 1MB. Copying it to an archive and emptying it brought the 50 ms for REM down to 4 ms. I think I'll make a task to do that regularly. I don't normally use $= in my prompt, but keeping the log file small will speed everything up even when I'm not timing anything.

I'm a little surprised that seeking to the end of a 1MB file takes that long.
 
Charles Dye said:
I guess you could move your log files to a RAMdisk.... :rolleyes:
Click to expand...
That's not very permanent. I like having a record of everything I've done. I don't like figuring out difficult command lines (DUMPEL.EXE comes to mind) years after I last used them.

That said ... I used to love ramdisk.sys. Are there any modern ones? ... that automatically backup/restore their contents at shutdown/startup?
 
vefatica said:
Oh, well! No big deal. TIMER works well.

My history log was about 1MB. Copying it to an archive and emptying it brought the 50 ms for REM down to 4 ms. I think I'll make a task to do that regularly. I don't normally use $= in my prompt, but keeping the log file small will speed everything up even when I'm not timing anything.

I'm a little surprised that seeking to the end of a 1MB file takes that long.
Click to expand...

History logging uses Windows APIs call to request a semaphore to lock the file, open the file, seek to the end, write the command, close the file & release the semaphore. If you want all of that to run faster, you should contact Microsoft directly. (Or get a faster system!)
 
rconn said:
History logging uses Windows APIs call to request a semaphore to lock the file, open the file, seek to the end, write the command, close the file & release the semaphore. If you want all of that to run faster, you should contact Microsoft directly. (Or get a faster system!)
Click to expand...
My new computer seems pretty fast ... 3.5MHz, SSDs, 16GB RAM. How much faster do workstations get?
 
vefatica said:
... nothing!
Click to expand...

Did you create the virtual Disk in virtual or physical memory?
1574278370300.png

Not sure if it will make any difference, though.

Joe
 
Joe Caverly said:
Did you create the virtual Disk in virtual or physical memory?
View attachment 2593
Not sure if it will make any difference, though.

Joe
Click to expand...
It was in virtual memory. So I tried again, putting it in physical memory ... no difference. When I copied my archived 1MB history log to the ramdrive history log, the $= time for REM went right back to 50 ms. I guess the moral of the story is that the SSD is pretty fast and the Win32 APIs that Rex described are the limiting factor.
 
You must log in or register to reply here.
Back
Top
[FOX] Ultimate Translator
Translate