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.