Why is a GOTO loop much slower than a FOR loop and depends additionally on power supply?

  • A+
Category:Languages

I wrote a small batch file to convert a file containing eight 16 bit hexadecimal values per line into a CSV file with the eight values in decimal.

The input data file was the captured output of ADC values of an embedded device sent in packets of eight hexadecimal values in ASCII with carriage return plus line-feed via RS-232 to PC and simply captured on PC into a file. One line in input data file was something like:

000A002D0044008B0125018C01F40237 

The CSV file for this line was:

10,45,68,139,293,396,500,567 

The batch file worked, but it took several minutes to complete the conversion which shocked me. I expected that Windows command processor takes some seconds for this task which a console application written in C or C++ could to in some milliseconds. But an execution time of several minutes for a data file with less than 512 KiB was definitely not expected by me.

So I looked further on this issue with creating a batch file using four different methods to create a CSV file with decimal values from a data file with hexadecimal values.

The complete batch file for testing the four methods is appended below as well as my test results.

I understand that the first two methods using a subroutine are much slower than the last two methods doing the conversion in one loop with output each CSV line into file on each loop iteration respectively once at end of FOR loop because of calling a subroutine causes several additional steps done by cmd.exe which altogether take a lot of time on doing subroutine calling thousands of times.

But I do not really understand why first method using a GOTO loop is about six times slower than FOR loop with nearly the same two command lines.

Batch file code of method 1:

@echo off setlocal EnableExtensions EnableDelayedExpansion set "DelDataFile=" set "DataFile=%TEMP%/HexValues.dat" if not exist "%DataFile%" set "DelDataFile=1" & echo 000A002D0044008B0125018C01F40237>"%DataFile%"  for /F "usebackq delims=" %%I in ("%DataFile%") do call :ConvertLine "%%I"  if defined DelDataFile del "%DataFile%" endlocal goto :EOF  :ConvertLine set "DataLine=%~1" set "AllValues=" set "StartColumn=0" :NextValue set /A Value=0x!DataLine:~%StartColumn%,4! set "AllValues=%AllValues%,%Value%" set /A StartColumn+=4 if not %StartColumn% == 32 goto NextValue echo %AllValues:~1% goto :EOF 

Batch file code of method 2:

@echo off setlocal EnableExtensions EnableDelayedExpansion set "DelDataFile=" set "DataFile=%TEMP%/HexValues.dat" if not exist "%DataFile%" set "DelDataFile=1" & echo 000A002D0044008B0125018C01F40237>"%DataFile%"  for /F "usebackq delims=" %%I in ("%DataFile%") do call :LineConvert "%%I"  if defined DelDataFile del "%DataFile%" endlocal goto :EOF  :LineConvert set "DataLine=%~1" set "AllValues=" for /L %%J in (0,4,28) do (     set /A Value=0x!DataLine:~%%J,4!     set "AllValues=!AllValues!,!Value!" ) echo !AllValues:~1! goto :EOF 

And I discovered additionally on running tests to find out the reason by myself that method 1 takes 5 to 10 seconds longer on PC running on battery than on power supply being plugged in.

The question:

What is the reason for much slower execution of the GOTO loop used by method 1 in comparison to the FOR loop used by method 2 and why does method 1 depend on kind of power supply of PC?


Here is the entire batch file being used to compare the different methods:

@echo off setlocal EnableExtensions EnableDelayedExpansion cls set "TestRuns=5" set "DelDataFile=" set "DataFile=%TEMP%/HexValues.dat" if exist "%DataFile%" goto InitMethod1  set "DelDataFile=1" echo Creating data file which takes some seconds, please wait ... setlocal set "HexDigits=0123456789ABCDEF" set "DataLine=" (for /L %%I in (0,1,32767) do (     set /A "Digit1=(%%I >> 12) %% 16"     set /A "Digit2=(%%I >> 8) %% 16"     set /A "Digit3=(%%I >> 4) %% 16"     set /A "Digit4=%%I %% 16"     set "HexValue="     for %%J in (!Digit1! !Digit2! !Digit3! !Digit4!) do set "HexValue=!HexValue!!HexDigits:~%%J,1!"     set "DataLine=!DataLine!!HexValue!"     set /A "ValuesPerLine=%%I %% 8"     if !ValuesPerLine! == 7 (         echo !DataLine!         set "DataLine="     ) ))>"%DataFile%" endlocal echo/   :InitMethod1 call :MethodInit 1 :RunMethod1 set /A TestRun+=1 set "CSV_File=%TEMP%/Values%Method%_%TestRun%.csv" del "%CSV_File%" 2>nul call :GetTime StartTime  for /F "usebackq delims=" %%I in ("%DataFile%") do call :ConvertLine "%%I"  call :OutputTime if %TestRun% LSS %TestRuns% goto RunMethod1 call :MethodResults goto InitMethod2  :ConvertLine set "DataLine=%~1" set "AllValues=" set "StartColumn=0" :NextValue set /A Value=0x!DataLine:~%StartColumn%,4! set "AllValues=%AllValues%,%Value%" set /A StartColumn+=4 if not %StartColumn% == 32 goto NextValue >>"%CSV_File%" echo %AllValues:~1% goto :EOF   :InitMethod2 call :MethodInit 2 :RunMethod2 set /A TestRun+=1 set "CSV_File=%TEMP%/Values%Method%_%TestRun%.csv" del "%CSV_File%" 2>nul call :GetTime StartTime  for /F "usebackq delims=" %%I in ("%DataFile%") do call :LineConvert "%%I"  call :OutputTime if %TestRun% LSS %TestRuns% goto RunMethod2 call :MethodResults goto InitMethod3  :LineConvert set "DataLine=%~1" set "AllValues=" for /L %%J in (0,4,28) do (     set /A Value=0x!DataLine:~%%J,4!     set "AllValues=!AllValues!,!Value!" ) echo !AllValues:~1!>>"%CSV_File%" goto :EOF   :InitMethod3 call :MethodInit 3 :RunMethod3 set /A TestRun+=1 set "CSV_File=%TEMP%/Values%Method%_%TestRun%.csv" del "%CSV_File%" 2>nul call :GetTime StartTime  for /F "usebackq delims=" %%I in ("%DataFile%") do (     set "DataLine=%%I"     set "AllValues="     for /L %%J in (0,4,28) do (         set /A Value=0x!DataLine:~%%J,4!         set "AllValues=!AllValues!,!Value!"     )     echo !AllValues:~1!>>"%CSV_File%" )  call :OutputTime if %TestRun% LSS %TestRuns% goto RunMethod3 call :MethodResults goto InitMethod4   :InitMethod4 call :MethodInit 4 :RunMethod4 set /A TestRun+=1 set "CSV_File=%TEMP%/Values%Method%_%TestRun%.csv" del "%CSV_File%" 2>nul call :GetTime StartTime  (for /F "usebackq delims=" %%I in ("%DataFile%") do (     set "DataLine=%%I"     set "AllValues="     for /L %%J in (0,4,28) do (         set /A Value=0x!DataLine:~%%J,4!         set "AllValues=!AllValues!,!Value!"     )     echo !AllValues:~1! ))>>"%CSV_File%"  call :OutputTime if %TestRun% LSS %TestRuns% goto RunMethod4 call :MethodResults goto EndBatch   :GetTime for /F "tokens=2 delims==." %%I in ('%SystemRoot%/System32/wbem/wmic.exe OS GET LocalDateTime /VALUE') do set "%1=%%I" goto :EOF  :MethodInit set "Method=%1" echo Test runs with method %Method% echo ----------------------- echo/ set "TestRun=0" set "TotalTime=0" goto :EOF  :MethodResults set /A AverageTime=TotalTime / TestRun echo Method %Method% total time: %TotalTime% seconds echo Method %Method% average time: %AverageTime% seconds echo/ goto :EOF  :OutputTime call :GetTime EndTime set /A StartTime=(1%StartTime:~8,2% - 100) * 3600 + (1%StartTime:~10,2% - 100) * 60 + 1%StartTime:~12,2% - 100 set /A EndTime=(1%EndTime:~8,2% - 100) * 3600 + (1%EndTime:~10,2% - 100) * 60 + 1%EndTime:~12,2% - 100 set /A DiffTime=EndTime - StartTime set /A TotalTime+=DiffTime echo Method %Method% run %TestRun% time: %DiffTime% seconds goto :EOF   :EndBatch if defined DelDataFile del "%DataFile%" del /Q "%TEMP%/Values?_*.csv" endlocal 

It creates first the data file with incrementing hexadecimal values in folder for temporary files which take already some seconds. Please comment the antepenultimate command line of this batch file to keep that file in case of running this batch file multiple times or being interested in this file.

Then it runs five times the four methods for reading the hexadecimal values from data file and writing the values in decimal into a CSV file with printing the test results to console respectively handle STDOUT.

Finally it deletes all CSV files created also in folder for temporary files all having same content. Please comment last but one command line to keep those CSV files on being interested in those files.

This batch file was executed by me four times on two notebooks.

Here are the results of first run on a notebook with an Intel Core Duo P8400 with 2.26 GHz and 2 GiB RAM with a HDD with 7200 rpm running Windows XP x86 with power supply plugged in:

Test runs with method 1 -----------------------  Method 1 run 1 time: 51 seconds Method 1 run 2 time: 51 seconds Method 1 run 3 time: 51 seconds Method 1 run 4 time: 52 seconds Method 1 run 5 time: 51 seconds Method 1 total time: 256 seconds Method 1 average time: 51 seconds  Test runs with method 2 -----------------------  Method 2 run 1 time: 9 seconds Method 2 run 2 time: 9 seconds Method 2 run 3 time: 9 seconds Method 2 run 4 time: 8 seconds Method 2 run 5 time: 9 seconds Method 2 total time: 44 seconds Method 2 average time: 9 seconds  Test runs with method 3 -----------------------  Method 3 run 1 time: 3 seconds Method 3 run 2 time: 3 seconds Method 3 run 3 time: 4 seconds Method 3 run 4 time: 3 seconds Method 3 run 5 time: 3 seconds Method 3 total time: 16 seconds Method 3 average time: 3 seconds  Test runs with method 4 -----------------------  Method 4 run 1 time: 3 seconds Method 4 run 2 time: 2 seconds Method 4 run 3 time: 2 seconds Method 4 run 4 time: 2 seconds Method 4 run 5 time: 2 seconds Method 4 total time: 11 seconds Method 4 average time: 2 seconds 

Method 2 is 5.67 times faster than method 1. Method 3 and 4 are even faster than method 2, but that is expected by me. Most of the 2 and 3 seconds needed by methods 3 and 4 are from WMIC command to get local date and time in region independent format.

Here are the results of second run on same computer as first run with the difference on running the PC on full charged battery:

Test runs with method 1 -----------------------  Method 1 run 1 time: 63 seconds Method 1 run 2 time: 61 seconds Method 1 run 3 time: 61 seconds Method 1 run 4 time: 61 seconds Method 1 run 5 time: 61 seconds Method 1 total time: 307 seconds Method 1 average time: 61 seconds  Test runs with method 2 -----------------------  Method 2 run 1 time: 11 seconds Method 2 run 2 time: 10 seconds Method 2 run 3 time: 10 seconds Method 2 run 4 time: 10 seconds Method 2 run 5 time: 10 seconds Method 2 total time: 51 seconds Method 2 average time: 10 seconds  Test runs with method 3 -----------------------  Method 3 run 1 time: 3 seconds Method 3 run 2 time: 4 seconds Method 3 run 3 time: 3 seconds Method 3 run 4 time: 4 seconds Method 3 run 5 time: 3 seconds Method 3 total time: 17 seconds Method 3 average time: 3 seconds  Test runs with method 4 -----------------------  Method 4 run 1 time: 2 seconds Method 4 run 2 time: 2 seconds Method 4 run 3 time: 2 seconds Method 4 run 4 time: 2 seconds Method 4 run 5 time: 2 seconds Method 4 total time: 10 seconds Method 4 average time: 2 seconds 

It can be seen that for methods 2 to 4 the processing times increase just a little bit. But processing time of method 1 increases by 10 seconds and so this solution is now about 6.10 times slower than method 2. I have no idea why processing time of method 1 depends on kind of power supply.

Here are the results of first run on a notebook with an Intel Core Duo T9600 with 2.80 GHz and 4 GiB RAM with an SSD running Windows 7 x64 with power supply plugged in:

Test runs with method 1 -----------------------  Method 1 run 1 time: 91 seconds Method 1 run 2 time: 88 seconds Method 1 run 3 time: 77 seconds Method 1 run 4 time: 77 seconds Method 1 run 5 time: 78 seconds Method 1 total time: 411 seconds Method 1 average time: 82 seconds  Test runs with method 2 -----------------------  Method 2 run 1 time: 11 seconds Method 2 run 2 time: 16 seconds Method 2 run 3 time: 16 seconds Method 2 run 4 time: 14 seconds Method 2 run 5 time: 16 seconds Method 2 total time: 73 seconds Method 2 average time: 14 seconds  Test runs with method 3 -----------------------  Method 3 run 1 time: 6 seconds Method 3 run 2 time: 4 seconds Method 3 run 3 time: 4 seconds Method 3 run 4 time: 4 seconds Method 3 run 5 time: 6 seconds Method 3 total time: 24 seconds Method 3 average time: 4 seconds  Test runs with method 4 -----------------------  Method 4 run 1 time: 4 seconds Method 4 run 2 time: 3 seconds Method 4 run 3 time: 5 seconds Method 4 run 4 time: 4 seconds Method 4 run 5 time: 4 seconds Method 4 total time: 20 seconds Method 4 average time: 4 seconds 

It was interesting to see that the batch file execution with more powerful hardware takes more time on Windows 7 x64 than on Windows XP x86. But even more interesting for me is again the fact that method 2 is 5.86 times faster than method 1 just because of using a FOR instead of a GOTO loop.

For completeness the results of fourth run on same computer as third run with the difference on running the PC on full charged battery:

Test runs with method 1 -----------------------  Method 1 run 1 time: 97 seconds Method 1 run 2 time: 91 seconds Method 1 run 3 time: 90 seconds Method 1 run 4 time: 81 seconds Method 1 run 5 time: 77 seconds Method 1 total time: 436 seconds Method 1 average time: 87 seconds  Test runs with method 2 -----------------------  Method 2 run 1 time: 12 seconds Method 2 run 2 time: 16 seconds Method 2 run 3 time: 17 seconds Method 2 run 4 time: 16 seconds Method 2 run 5 time: 13 seconds Method 2 total time: 74 seconds Method 2 average time: 14 seconds  Test runs with method 3 -----------------------  Method 3 run 1 time: 6 seconds Method 3 run 2 time: 6 seconds Method 3 run 3 time: 5 seconds Method 3 run 4 time: 5 seconds Method 3 run 5 time: 5 seconds Method 3 total time: 27 seconds Method 3 average time: 5 seconds  Test runs with method 4 -----------------------  Method 4 run 1 time: 4 seconds Method 4 run 2 time: 4 seconds Method 4 run 3 time: 5 seconds Method 4 run 4 time: 4 seconds Method 4 run 5 time: 4 seconds Method 4 total time: 21 seconds Method 4 average time: 4 seconds 

There is again not much difference in execution time for the methods 3 to 4 in comparison to third run with power supply plugged in. But the execution time of method 1 increases by approximately 5 seconds and for that reason method 1 is 6.21 times slower than method 2.

I would be really interested in why method 1 is so much slower than method 2 and additionally depends on kind of power supply.

The hard disk activity LED was only very rarely blinking on all test runs as expected by me because of Windows file caching.

 


According to this analysis of the interpreter, the FOR variable will be expanded in phase 4, so the interpreter will know how many times to execute the command and on what values immediately. In contrast, each GOTO is interpreted in phase 7, and it requires scanning the file anew looking for the label each time, which accounts for the perceived time difference.

Comment

:?: :razz: :sad: :evil: :!: :smile: :oops: :grin: :eek: :shock: :???: :cool: :lol: :mad: :twisted: :roll: :wink: :idea: :arrow: :neutral: :cry: :mrgreen: