Why? File Read in HALF the time by using extraneous )> %2

Discussion forum for all Windows batch related topics.

Moderator: DosItHelp

Message
Author
alan_b
Expert
Posts: 357
Joined: 04 Oct 2008 09:49

Why? File Read in HALF the time by using extraneous )> %2

#1 Post by alan_b » 24 Feb 2012 06:27

I came to bump my post of two days ago, and realized the Title was incorrect because of the massive difficulty caused by the very short length of Title allowed.

I am going to read 771 lines from a file consisting of an index number followed by text, and store each number in an array of variables.
I have no need to write anything to an output file.
BUT I can read the input file NEARLY TWICE AS FAST if I write each line to an output file
and EVEN FASTER if I refrain from writing each line BUT write a null output to an output file.

I discovered this peculiarity when reading a file and writing an output of the same text preceded by an incrementing line count,
and I wondered how much time was consumed by each element of code within the loop,
and was surprised that it took NEARLY TWICE AS LONG to read the file when I removed the element that created the output file.
This is so counter-intuitive.

WHY does writing an output file speed up the reading of an Input File ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ?

This is the code in question.

Code: Select all

:X1
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET "LN=" & SET /P "LN="
    ECHO %%j    !LN!
  )
) > %2
SET "T_Str=:CALLED %0 ; ECHO %%j    LN to %1"
%DIF#%
EXIT/B

That code as shown takes 260 mSec to :-
read 771 lines from a 25 kByte file; and
write the same with an incrementing prefix to a 33 kByte file

:X2 Is the same code after removing the line ECHO %%j !LN!
and this is 60 mSec faster because there is no output so File %2 is forced to size zero.
No surprise there.

:X3 suffers the extra removal of > %2
and that strangely INCREASES the execution time to 430 mSec

Having created "Input.txt" I know that there are no empty lines,
and therefore see no reason to include any SET "LN="
:X4 to :X6 are 60 mSec FASTER variants of :X1 to :X3 in which I have removed

Code: Select all

      SET "LN=" &

As a "practical example" of when an output file is NOT needed,
:Y5 and :Y6 simply read the input file and increment a variable when the line says "Have a Nice Day"
By using " > %2 " and setting Output.txt to size zero, :Y5 spends 150 mSec
By omitting " > %2 " and doing nothing to Output.txt, :Y6 spends 390 mSec

The mathematics suggests that when only one file is used,
Windows Ultimate allocates only one core from my quad core processor to my needs.
But when two files are used a state of emergency is declared,
and Windows Ultimate allocates ALL four cores from my quad core processor to my needs.

Please rescue my sanity and tell me what is happening :roll:

This is the start of Input.txt

Code: Select all

100001 [ *]
100003 [.NET Framework Logs*]
100004 [.NET Reflector*]
100002 [.Thumbnails*]
100005 [32bit Web Browser*]

This is the start of Output.txt

Code: Select all

100001 100001 [ *]
100002 100003 [.NET Framework Logs*]
100003 100004 [.NET Reflector*]
100004 100002 [.Thumbnails*]
100005 100005 [32bit Web Browser*]

This is what I captured from a DOS window.
Press any key to continue . . .

E:\T\CCleaner\New\SRx2\#TRIMMER>#
FILE #.bat CREATED 19:06 22/02/2012 Launched 21:02:02.24
LO=100001 ; HI=100771
21:02:02.54 - 21:02:02.29 = 250 mSec :CALLED :X1 ; ECHO %j LN to Output.txt
21:02:02.80 - 21:02:02.55 = 250 mSec :CALLED :X1 ; ECHO %j LN to Output.txt
21:02:03.00 - 21:02:02.81 = 190 mSec :CALLED :X2 ; No output, zero size Output.txt
21:02:03.20 - 21:02:03.01 = 190 mSec :CALLED :X2 ; No output, zero size Output.txt
21:02:03.63 - 21:02:03.20 = 430 mSec :CALLED :X3 ; No Output, No Output File
21:02:04.06 - 21:02:03.64 = 420 mSec :CALLED :X3 ; No Output, No Output File
21:02:04.26 - 21:02:04.07 = 190 mSec :CALLED :X4 ; No "LN=", ECHO %j LN to Output.txt
21:02:04.46 - 21:02:04.27 = 190 mSec :CALLED :X4 ; No "LN=", ECHO %j LN to Output.txt
21:02:04.61 - 21:02:04.47 = 140 mSec :CALLED :X5 ; No "LN=", No output, zero size Output.txt
21:02:04.75 - 21:02:04.61 = 140 mSec :CALLED :X5 ; No "LN=", No output, zero size Output.txt
21:02:05.12 - 21:02:04.75 = 370 mSec :CALLED :X6 ; No "LN=", No Output, No Output File
21:02:05.49 - 21:02:05.13 = 360 mSec :CALLED :X6 ; No "LN=", No Output, No Output File
21:02:05.65 - 21:02:05.50 = 150 mSec :CALLED :Y5 ; "NICE = 0", zero size Output.txt
21:02:05.80 - 21:02:05.66 = 140 mSec :CALLED :Y5 ; "NICE = 0", zero size Output.txt
21:02:06.20 - 21:02:05.81 = 390 mSec :CALLED :Y6 ; "NICE = 0", No Output File
21:02:06.59 - 21:02:06.20 = 390 mSec :CALLED :Y6 ; "NICE = 0", No Output File
21:02:06.79 - 21:02:06.60 = 190 mSec :CALLED :X4 ; No "LN=", ECHO %j LN to Output.txt
21:02:06.80 - 21:02:02.24 = 4560 mSec Duration of Above Tests
Press any key to continue . . .

E:\T\CCleaner\New\SRx2\#TRIMMER>

This is my script under the name #.bat

Code: Select all

@echo off
SET "T_Str=In_Line Measurement"
SET "N_1=SET "T_1=!TIME!" & FOR /F "tokens=1-4 delims=:." %%d in ("!T_1!") do (SET /A V_1=%%d*360000+1%%e*6000+1%%f*100+1%%g-610100)"
SET "N_2=SET "T_2=!TIME!" & FOR /F "tokens=1-4 delims=:." %%d in ("!T_2!") do (SET /A V_2=%%d*360000+1%%e*6000+1%%f*100+1%%g-610100)"
SET "DIF=SET /A DELAY=!V_2!-!V_1! & ECHO !T_2! - !T_1! = !DELAY!0 mSec !T_Str!"
SET "DIF#=%N_2% & %DIF%"

setlocal EnableDelayedExpansion
ECHO FILE %~nx0 CREATED 19:06 22/02/2012   Launched %TIME%

%N_1%
SETLOCAL

SET "T_Str=Within SETLOCAL In_Line Measurement"

SET LO=100001
for /f %%a in ('find /c /v "" ^< Input.txt') do SET /A HI=%LO%-1+%%a

ECHO LO=!LO! ; HI=!HI!
CALL :X1 Input.txt Output.txt
CALL :X1 Input.txt Output.txt
CALL :X2 Input.txt Output.txt
CALL :X2 Input.txt Output.txt
CALL :X3 Input.txt
CALL :X3 Input.txt

CALL :X4 Input.txt Output.txt
CALL :X4 Input.txt Output.txt
CALL :X5 Input.txt Output.txt
CALL :X5 Input.txt Output.txt
CALL :X6 Input.txt
CALL :X6 Input.txt
SET NICE=0
CALL :Y5 Input.txt Output.txt
CALL :Y5 Input.txt Output.txt
CALL :Y6 Input.txt
CALL :Y6 Input.txt

CALL :X4 Input.txt Output.txt

SET "T_Str=Duration of Above Tests"
%DIF#%

PAUSE
EXIT /B

:X1
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET "LN=" & SET /P "LN="
    ECHO %%j    !LN!
  )
) > %2
SET "T_Str=:CALLED %0 ; ECHO %%j    LN to %2"
%DIF#%
EXIT/B

:X2
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET "LN=" & SET /P "LN="
  )
) > %2
SET "T_Str=:CALLED %0 ; No output, zero size %2"
%DIF#%
EXIT/B

:X3
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET "LN=" & SET /P "LN="
  )
)
SET "T_Str=:CALLED %0 ; No Output, No Output File"
%DIF#%
EXIT/B

:X4
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
    ECHO %%j    !LN!
  )
) > %2
SET "T_Str=:CALLED %0 ; No "LN=", ECHO %%j    LN to %2"
%DIF#%
EXIT/B

:X5
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
  )
) > %2
SET "T_Str=:CALLED %0 ; No "LN=", No output, zero size %2"
%DIF#%
EXIT/B

:X6
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
  )
)
SET "T_Str=:CALLED %0 ; No "LN=", No Output, No Output File"
%DIF#%
EXIT/B

:Y5
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
    IF "!LN!"=="Have a nice day" SET /A NICE+=1
  )
) > %2
SET "T_Str=:CALLED %0 ; "NICE = !NICE!", zero size %2"
%DIF#%
EXIT/B

:Y6
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
    IF "!LN!"=="Have a nice day" SET /A NICE+=1
  )
)
SET "T_Str=:CALLED %0 ; "NICE = !NICE!", No Output File"
%DIF#%
EXIT/B

Regards
Alan

foxidrive
Expert
Posts: 6031
Joined: 10 Feb 2012 02:20

Re: Why? File Read in HALF the time by using extraneous )> %

#2 Post by foxidrive » 24 Feb 2012 17:33

Snip whinge ;)
Last edited by foxidrive on 24 Feb 2012 19:18, edited 1 time in total.

foxidrive
Expert
Posts: 6031
Joined: 10 Feb 2012 02:20

Re: Why? File Read in HALF the time by using extraneous )> %

#3 Post by foxidrive » 24 Feb 2012 17:42

So I created the batch file, and copied input.txt from your example multiple times to get 771 odd lines, and get the following, but I'm no wiser.

Code: Select all

FILE A.BAT CREATED 19:06 22/02/2012   Launched 10:45:22.57
LO=100001 ; HI=100770
10:45:22.85 - 10:45:22.75 = 100 mSec :CALLED :X1 ; ECHO %j    LN to Output.txt
10:45:22.96 - 10:45:22.85 = 110 mSec :CALLED :X1 ; ECHO %j    LN to Output.txt
10:45:23.04 - 10:45:22.96 = 80 mSec :CALLED :X2 ; No output, zero size Output.txt
10:45:23.10 - 10:45:23.04 = 60 mSec :CALLED :X2 ; No output, zero size Output.txt
10:45:23.18 - 10:45:23.10 = 80 mSec :CALLED :X3 ; No Output, No Output File
10:45:23.26 - 10:45:23.18 = 80 mSec :CALLED :X3 ; No Output, No Output File
10:45:23.34 - 10:45:23.26 = 80 mSec :CALLED :X4 ; No "LN=", ECHO %j    LN to Output.txt
10:45:23.42 - 10:45:23.34 = 80 mSec :CALLED :X4 ; No "LN=", ECHO %j    LN to Output.txt
10:45:23.48 - 10:45:23.42 = 60 mSec :CALLED :X5 ; No "LN=", No output, zero size Output.txt
10:45:23.53 - 10:45:23.48 = 50 mSec :CALLED :X5 ; No "LN=", No output, zero size Output.txt
10:45:23.59 - 10:45:23.53 = 60 mSec :CALLED :X6 ; No "LN=", No Output, No Output File
10:45:23.65 - 10:45:23.59 = 60 mSec :CALLED :X6 ; No "LN=", No Output, No Output File
10:45:23.71 - 10:45:23.65 = 60 mSec :CALLED :Y5 ; "NICE = 0", zero size Output.txt
10:45:23.78 - 10:45:23.71 = 70 mSec :CALLED :Y5 ; "NICE = 0", zero size Output.txt
10:45:23.84 - 10:45:23.78 = 60 mSec :CALLED :Y6 ; "NICE = 0", No Output File
10:45:23.90 - 10:45:23.84 = 60 mSec :CALLED :Y6 ; "NICE = 0", No Output File
10:45:23.98 - 10:45:23.90 = 80 mSec :CALLED :X4 ; No "LN=", ECHO %j    LN to Output.txt
10:45:23.98 - 10:45:22.57 = 1410 mSec Duration of Above Tests
Press any key to continue . . .

dbenham
Expert
Posts: 2461
Joined: 12 Feb 2011 21:02
Location: United States (east coast)

Re: Why? File Read in HALF the time by using extraneous )> %

#4 Post by dbenham » 24 Feb 2012 20:29

Very curious, but I think I may have solved the mystery :idea: :)

I'm just not sure how to prove it.

Every test case does have some output - the SET /P has a prompt. It just so happens that your prompt is empty, but I suppose SET still goes through the motions of displaying the prompt.

The test cases with redirected output are faster because writing to a file is always faster then writing to the screen (assuming a healthy disk drive). Apparently this is still true even if the output is an empty string :!:

I thought redirecting output of SET /P to null might help, but it actually slows things down because of the overhead of setting up redirection for each iteration.

Dave Benham

alan_b
Expert
Posts: 357
Joined: 04 Oct 2008 09:49

Re: Why? File Read in HALF the time by using extraneous )> %

#5 Post by alan_b » 25 Feb 2012 02:37

:idea: :idea: :idea: Yes Indeed.

Code: Select all

SET /P ANS= "Please Enter your Name : "
SET /P ANS= "%String%"

In the above "SET /P" will output messages, presumably even if %String% is zero length.

Each line in an input file is read by the code
set /p "LN="

I can accept that perhaps %String% will be output as each line is read by a

Code: Select all

set /p "LN=" "%String%"

In which case the output mechanism exists even when %String% is Null,
perhaps even when the zero length string is not surrounded by "quotes".

Thank you, I am much happier to use a technique when I think I know how it works,
and that it is not subject to mystic cosimic forces and the alignment of the planets :roll:

Regards
Alan

foxidrive
Expert
Posts: 6031
Joined: 10 Feb 2012 02:20

Re: Why? File Read in HALF the time by using extraneous )> %

#6 Post by foxidrive » 25 Feb 2012 02:42

Do my results back up yours, Alan? It certainly seems radically different in ratios and the method with an output file is longer in duration.

alan_b
Expert
Posts: 357
Joined: 04 Oct 2008 09:49

Re: Why? File Read in HALF the time by using extraneous )> %

#7 Post by alan_b » 25 Feb 2012 02:58

I like your theory and will do some tests later today,
which involves shutting off the Internet and disabling all malware protection to avoid any consequent delays.

I admit your results do NOT agree with mine.

I hesitate to burden the forum servers with my entire 771 line file.
I will come back later with a short script that creates an apparently pseudo random but exactly repeatable 771 line file,
so that we can compare results under the same conditions
- unless of course you have only a single core processor and I am experience the transition into 4 cores cooperating when there is output as well as input :roll: :roll: :roll: :roll:

Regards
Alan

foxidrive
Expert
Posts: 6031
Joined: 10 Feb 2012 02:20

Re: Why? File Read in HALF the time by using extraneous )> %

#8 Post by foxidrive » 25 Feb 2012 03:06

alan_b wrote:I admit your results do NOT agree with mine.

I hesitate to burden the forum servers with my entire 771 line file.

- unless of course you have only a single core processor and I am experience the transition into 4 cores cooperating


Upload the file to some provider - dropbox etc? Your web space with your ISP?


My CPU is an Intel 4 core jobby.

alan_b
Expert
Posts: 357
Joined: 04 Oct 2008 09:49

Re: Why? File Read in HALF the time by using extraneous )> %

#9 Post by alan_b » 25 Feb 2012 03:20

Thanks, yes I will upload - but not DropBox.
I think it was DropBox that my son used for our grandchildren's photos.
I installed DropBox (or whatever it was) and subsequently discovered my context menus became elusive jittery phantoms.
I use AutoRuns and that showed my that DropBox had sunk TEN different hooks into Explorer.

I discovered that one of the hooks even caused a new DropBox log file to be created every time the computer started.
The absolute worst thing about that was each such file had a date/time stamp that exactly matched the time stamp of the very first start-up event in the XP System Event log.
Drop-Box started when (or possibly before) the computer had completed the BIOS :evil: :evil:

Regards
Alan

alan_b
Expert
Posts: 357
Joined: 04 Oct 2008 09:49

Re: Why? File Read in HALF the time by using extraneous )> %

#10 Post by alan_b » 25 Feb 2012 06:05

My file Input.txt can be downloaded via
http://minus.com/mnQfjIach

I find that the correct syntax for output via SET /P is
SET /P "LN= Output Text"

My new test case :Y7 demonstrates with
SET /P "LN= %%j, !LN!"

My new code produces this output
E:\T\CCleaner\New\SRx2\#TRIMMER>]
FILE ].bat CREATED 19:06 22/02/2012 Launched 11:17:12.39
LO=100001 ; HI=100771
11:17:12.64 - 11:17:12.44 = 200 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
11:17:12.84 - 11:17:12.64 = 200 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
11:17:12.99 - 11:17:12.85 = 140 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
11:17:13.14 - 11:17:13.00 = 140 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
11:17:13.53 - 11:17:13.15 = 380 mSec :CALLED :Y6 ; "NICE = 0", No Output File
11:17:13.92 - 11:17:13.54 = 380 mSec :CALLED :Y6 ; "NICE = 0", No Output File
11:17:14.08 - 11:17:13.93 = 150 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
11:17:14.25 - 11:17:14.09 = 160 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
11:17:14.25 - 11:17:12.40 = 1850 mSec Duration of Above Tests
Press any key to continue . . .


:X4 takes 200 mSec to create Output.txt
:Y5 is 60 mSec faster because there is one less line of code in the loop - there is no ECHO

:Y7 creates Output7.txt and is almost as fast as :Y5 for the same reason - no line of code with ECHO.
Output7.txt differs from Output.txt in that it has no CR/LF terminators between lines,
hence Output7.txt is 29.1 KB (29,871 bytes) whilst Output.txt is 32.2 KB (32,999 bytes).
Also, the first and last few "lines" have show the previous line of text, e.g.

Output.txt :-
100001 100001 [ *]
100002 100003 [.NET Framework Logs*]
100003 100004 [.NET Reflector*]
....
100769 100769 [Zune (Transcoded Files Cache)*]
100770 100770 [Zuse Logs*]
100771 100771 [ZX32 ZX Spectrum Emulator v1.03*]


Output7.txt - after I inserted CR/LF terminators for this post :-
100001,
100002, 100001 [ *]
100003, 100003 [.NET Framework Logs*]
100004, 100004 [.NET Reflector*]
....
100769, 100768 [ZoneAlarm Internet Logs*]
100770, 100769 [Zune (Transcoded Files Cache)*]
100771, 100770 [Zuse Logs*]


Incase it is relevant :-
I am using Windows 7 Ultimate + SP1 on a x64 System.
I have an AMD processor, not Intel,
Speccy reports :-
CPU
AMD Phenom X4 9500
Cores 4
Threads 4
Name AMD Phenom X4 9500
Code Name Agena
Package Socket AM2+ (940)
Technology 65nm
Specification AMD Phenom(tm) 9500 Quad-Core Processor
Family F
Extended Family 10
Model 2
Extended Model 2
Stepping 2
Revision DR-B2
Instructions MMX (+), 3DNow! (+), SSE, SSE2, SSE3, SSE4A, AMD 64
Virtualization Supported, Disabled
Hyperthreading Not supported
Fan Speed 4326 RPM
Bus Speed 200.6 MHz
Rated Bus Speed 1805.4 MHz
Stock Core Speed 2200 MHz
Stock Bus Speed 200 MHz
Average Temperature 46 °C
Caches
L1 Data Cache Size 4 x 64 KBytes
L1 Instructions Cache Size 4 x 64 KBytes
L2 Unified Cache Size 4 x 512 KBytes
L3 Unified Cache Size 2048 KBytes
Core 0
Core Speed 2206.7 MHz
Multiplier x 11.0
Bus Speed 200.6 MHz
Rated Bus Speed 1805.4 MHz
Temperature 46 °C
Thread 1
APIC ID 0

N.B. Cores 1,2,and 3 show exactly the same as Core 0

My new code is called "].bat" - I find ] and # are so conveniently close to Return :)

Code: Select all

@echo off & SETLOCAL DISABLEDELAYEDEXPANSION
SET "T_Str=In_Line Measurement"
SET "N_1=SET "T_1=!TIME!" & FOR /F "tokens=1-4 delims=:." %%d in ("!T_1!") do (SET /A V_1=%%d*360000+1%%e*6000+1%%f*100+1%%g-610100)"
SET "N_2=SET "T_2=!TIME!" & FOR /F "tokens=1-4 delims=:." %%d in ("!T_2!") do (SET /A V_2=%%d*360000+1%%e*6000+1%%f*100+1%%g-610100)"
SET "DIF=SET /A DELAY=!V_2!-!V_1! & ECHO !T_2! - !T_1! = !DELAY!0 mSec !T_Str!"
SET "DIF#=%N_2% & %DIF%"

setlocal EnableDelayedExpansion
ECHO FILE %~nx0 CREATED 19:06 22/02/2012   Launched %TIME%

%N_1%
SETLOCAL

SET "T_Str=Within SETLOCAL In_Line Measurement"

SET LO=100001
for /f %%a in ('find /c /v "" ^< Input.txt') do SET /A HI=%LO%-1+%%a

ECHO LO=!LO! ; HI=!HI!
CALL :X4 Input.txt Output.txt
CALL :X4 Input.txt Output.txt
SET NICE=0
CALL :Y5 Input.txt Output5.txt
CALL :Y5 Input.txt Output5.txt
CALL :Y6 Input.txt
CALL :Y6 Input.txt
CALL :Y7 Input.txt Output7.txt
CALL :Y7 Input.txt Output7.txt

SET "T_Str=Duration of Above Tests"
%DIF#%

PAUSE
EXIT /B

:X4
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
    ECHO %%j    !LN!
  )
) > %2
SET "T_Str=:CALLED %0 ; ECHO %%j    LN to %2"
%DIF#%
EXIT/B

:Y5
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
    IF "!LN!"=="Have a nice day" SET /A NICE+=1
  )
) > %2
SET "T_Str=:CALLED %0 ; "NICE = !NICE!", zero size %2"
%DIF#%
EXIT/B

:Y6
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
    IF "!LN!"=="Have a nice day" SET /A NICE+=1
  )
)
SET "T_Str=:CALLED %0 ; "NICE = !NICE!", No Output File"
%DIF#%
EXIT/B

:Y7
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN= %%j, !LN!"
    IF "!LN!"=="Have a nice day" SET /A NICE+=1
  )
) > %2
SET "T_Str=:CALLED %0 ; PROMPT %%j,  old'LN' to  %2"
%DIF#%
EXIT/B


Regards
Alan

foxidrive
Expert
Posts: 6031
Joined: 10 Feb 2012 02:20

Re: Why? File Read in HALF the time by using extraneous )> %

#11 Post by foxidrive » 25 Feb 2012 06:38

alan_b wrote:My file Input.txt can be downloaded via
http://minus.com/mnQfjIach

My new code produces this output
E:\T\CCleaner\New\SRx2\#TRIMMER>]
FILE ].bat CREATED 19:06 22/02/2012 Launched 11:17:12.39
LO=100001 ; HI=100771
11:17:12.64 - 11:17:12.44 = 200 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
11:17:12.84 - 11:17:12.64 = 200 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
11:17:12.99 - 11:17:12.85 = 140 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
11:17:13.14 - 11:17:13.00 = 140 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
11:17:13.53 - 11:17:13.15 = 380 mSec :CALLED :Y6 ; "NICE = 0", No Output File
11:17:13.92 - 11:17:13.54 = 380 mSec :CALLED :Y6 ; "NICE = 0", No Output File
11:17:14.08 - 11:17:13.93 = 150 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
11:17:14.25 - 11:17:14.09 = 160 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
11:17:14.25 - 11:17:12.40 = 1850 mSec Duration of Above Tests
Press any key to continue . . .


Here is my result.
FILE A.BAT CREATED 19:06 22/02/2012 Launched 23:37:02.59
LO=100001 ; HI=100771
23:37:02.86 - 23:37:02.76 = 100 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
23:37:02.95 - 23:37:02.86 = 90 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
23:37:03.03 - 23:37:02.95 = 80 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
23:37:03.09 - 23:37:03.03 = 60 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
23:37:03.15 - 23:37:03.09 = 60 mSec :CALLED :Y6 ; "NICE = 0", No Output File
23:37:03.23 - 23:37:03.17 = 60 mSec :CALLED :Y6 ; "NICE = 0", No Output File
23:37:03.31 - 23:37:03.23 = 80 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
23:37:03.39 - 23:37:03.31 = 80 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
23:37:03.39 - 23:37:02.59 = 800 mSec Duration of Above Tests
Press any key to continue . . .


Windows XP Pro SP3 - 32 bit

alan_b
Expert
Posts: 357
Joined: 04 Oct 2008 09:49

Re: Why? File Read in HALF the time by using extraneous )> %

#12 Post by alan_b » 25 Feb 2012 10:08

Thanks for the feedback.

I observe that :-

:Y7 is 20% faster than :X4 on your system
and 25% faster on mine.
Conclusion :- When outputting whilst reading, Execution Time of a single loop is proportional to the number of lines of code executed
That we have in common.

:Y5 is 25% faster than :X4 on your system
and 30% faster on mine.
Conclusions :- similar to above
Observation :- it is so unfair, your system is twice as fast as mine :o

:Y6 is 40% faster than :X4 on your system
and 90% SLOWER on mine.

I have a problem, much as Dave stated above
I thought redirecting output of SET /P to null might help, but it actually slows things down because of the overhead of setting up redirection for each iteration.

In fact it was previously explained in earlier threads that it took a long time to copy a file one line at a time via
ECHO(!LN!>%2
and much faster if the ">%2" was relocated to the ")" that closes the loop.

That theory is FACT on my machine as shown by
E:\T\CCleaner\New\SRx2\#TRIMMER>]
FILE ].bat CREATED 19:06 22/02/2012 Launched 15:46:40.99
LO=100001 ; HI=100771
15:46:41.23 - 15:46:41.04 = 190 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
15:46:41.43 - 15:46:41.24 = 190 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
15:46:42.43 - 15:46:41.44 = 990 mSec :CALLED :X8 ; ECHO %j LN to Output8.txt
15:46:43.43 - 15:46:42.44 = 990 mSec :CALLED :X8 ; ECHO %j LN to Output8.txt
15:46:43.59 - 15:46:43.44 = 150 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
15:46:43.74 - 15:46:43.59 = 150 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
15:46:44.14 - 15:46:43.75 = 390 mSec :CALLED :Y6 ; "NICE = 0", No Output File
15:46:44.53 - 15:46:44.14 = 390 mSec :CALLED :Y6 ; "NICE = 0", No Output File
15:46:44.69 - 15:46:44.54 = 150 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
15:46:44.86 - 15:46:44.70 = 160 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
15:46:44.86 - 15:46:40.99 = 3870 mSec Duration of Above Tests
Press any key to continue . . .

In fact that shows appended output within the loop is 5 times slower than external redirection.

I would be interested in seeing your results.

These are my new code insertions :-

Code: Select all

CALL :X8 Input.txt Output8.txt
CALL :X8 Input.txt Output8.txt

inserted within
ECHO LO=!LO! ; HI=!HI!
CALL :X4 Input.txt Output.txt
CALL :X4 Input.txt Output.txt
CALL :X8 Input.txt Output8.txt
CALL :X8 Input.txt Output8.txt
SET NICE=0
CALL :Y5 Input.txt Output5.txt
CALL :Y5 Input.txt Output5.txt
CALL :Y6 Input.txt
CALL :Y6 Input.txt
CALL :Y7 Input.txt Output7.txt
CALL :Y7 Input.txt Output7.txt

and

Code: Select all

:X8
IF EXIST %2 DEL %2
SETLOCAL
%N_1%
<%1 (
  for /L %%j in (!LO!,1,!HI!) do (
    SET /P "LN="
    ECHO %%j    !LN!>> %2
  )
)
SET "T_Str=:CALLED %0 ; ECHO %%j    LN to %2"
%DIF#%
EXIT/B

Inserted above
:Y5
SETLOCAL
%N_1%
<%1 (
for /L %%j in (!LO!,1,!HI!) do (
SET /P "LN="
IF "!LN!"=="Have a nice day" SET /A NICE+=1
)
) > %2
SET "T_Str=:CALLED %0 ; "NICE = !NICE!", zero size %2"
%DIF#%
EXIT/B

Off Topic :-
I am accustomed to forum Code Boxes have expand/contract and/or scroll bars.
I thought this was also true of DOSTIPS.
Has some incompatibility developed between this forum and both my PaleMonn and Firefox ?

Regards
Alan

foxidrive
Expert
Posts: 6031
Joined: 10 Feb 2012 02:20

Re: Why? File Read in HALF the time by using extraneous )> %

#13 Post by foxidrive » 25 Feb 2012 16:43

alan_b wrote:
E:\T\CCleaner\New\SRx2\#TRIMMER>]
FILE ].bat CREATED 19:06 22/02/2012 Launched 15:46:40.99
LO=100001 ; HI=100771
15:46:41.23 - 15:46:41.04 = 190 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
15:46:41.43 - 15:46:41.24 = 190 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
15:46:42.43 - 15:46:41.44 = 990 mSec :CALLED :X8 ; ECHO %j LN to Output8.txt
15:46:43.43 - 15:46:42.44 = 990 mSec :CALLED :X8 ; ECHO %j LN to Output8.txt
15:46:43.59 - 15:46:43.44 = 150 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
15:46:43.74 - 15:46:43.59 = 150 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
15:46:44.14 - 15:46:43.75 = 390 mSec :CALLED :Y6 ; "NICE = 0", No Output File
15:46:44.53 - 15:46:44.14 = 390 mSec :CALLED :Y6 ; "NICE = 0", No Output File
15:46:44.69 - 15:46:44.54 = 150 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
15:46:44.86 - 15:46:44.70 = 160 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
15:46:44.86 - 15:46:40.99 = 3870 mSec Duration of Above Tests
Press any key to continue . . .



FILE A.BAT CREATED 19:06 22/02/2012 Launched 9:37:35.55
LO=100001 ; HI=100771
9:37:35.80 - 9:37:35.69 = 110 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
9:37:35.88 - 9:37:35.80 = 80 mSec :CALLED :X4 ; ECHO %j LN to Output.txt
9:37:36.16 - 9:37:35.90 = 260 mSec :CALLED :X8 ; ECHO %j LN to Output8.txt
9:37:36.49 - 9:37:36.16 = 330 mSec :CALLED :X8 ; ECHO %j LN to Output8.txt
9:37:36.57 - 9:37:36.49 = 80 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
9:37:36.68 - 9:37:36.57 = 110 mSec :CALLED :Y5 ; "NICE = 0", zero size Output5.txt
9:37:36.77 - 9:37:36.68 = 90 mSec :CALLED :Y6 ; "NICE = 0", No Output File
9:37:36.83 - 9:37:36.77 = 60 mSec :CALLED :Y6 ; "NICE = 0", No Output File
9:37:36.96 - 9:37:36.83 = 130 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
9:37:37.07 - 9:37:36.97 = 100 mSec :CALLED :Y7 ; PROMPT %j, old'LN' to Output7.txt
9:37:37.07 - 9:37:35.55 = 1520 mSec Duration of Above Tests
Press any key to continue . . .


No output file is the fastest here - which is logical and expected.

Maybe it is a 64 bit OS that causes these discrepancies - but you would need another person using a 64 OS to post results, and also a person using a 32 bit os to post results that confirm my tests.

dbenham
Expert
Posts: 2461
Joined: 12 Feb 2011 21:02
Location: United States (east coast)

Re: Why? File Read in HALF the time by using extraneous )> %

#14 Post by dbenham » 26 Feb 2012 00:43

Results on my Vista 64 machine are virtually identical to alan's.

I decided to write a really simple test to compare performance of writing to the screen vs. writing to nul vs. writing to a file. I set my window height to 1 to minimize the effect of screen scrolling.

Code: Select all

@echo off
setlocal

mode con lines=1

set t1=%time%
(
  for /l %%N in (1 1 10000) do echo(
)
set t2=%time%
(
  for /l %%N in (1 1 10000) do echo(
) >nul
set t3=%time%
(
  for /l %%N in (1 1 10000) do echo(
) >junk.txt
set t4=%time%

mode con lines=60

call :showTime "output to screen:" "%t1%" "%t2%"
call :showTime "output to nul:   " "%t2%" "%t3%"
call :showTime "output to file:  " "%t3%" "%t4%"
exit /b

:showTime
setlocal
for /f "tokens=1-4 delims=:." %%d in (%2) do set /a "t1=%%d*360000+1%%e*6000+1%%f*100+1%%g-610100"
for /f "tokens=1-4 delims=:." %%d in (%3) do set /a "t2=%%d*360000+1%%e*6000+1%%f*100+1%%g-610100, t=t2-t1"
echo %~1 %t%0 msec
exit /b

Results:

Code: Select all

output to screen: 1400 msec
output to nul:    720 msec
output to file:   450 msec


@foxidrive - I'm really curious as to what kind of profile your machine has with the above. I'm hoping your times are much more tightly clustered, which could explain why you are seeing different results with alan's script.

Dave Benham

foxidrive
Expert
Posts: 6031
Joined: 10 Feb 2012 02:20

Re: Why? File Read in HALF the time by using extraneous )> %

#15 Post by foxidrive » 26 Feb 2012 01:20

dbenham wrote:Results:

Code: Select all

output to screen: 1400 msec
output to nul:    720 msec
output to file:   450 msec



Three runs:

Code: Select all

output to screen: 710 msec
output to nul:    260 msec
output to file:   130 msec

output to screen: 700 msec
output to nul:    300 msec
output to file:   140 msec

output to screen: 840 msec
output to nul:    350 msec
output to file:   140 msec

Post Reply