calculate elapsed time of a script/command run in batch

Question

I am trying to calculate/instrument time taken for a command/script to execute. Here's the batch file:

@echo off

setlocal EnableDelayedExpansion

echo "Starting the script run...." & echo/


set "startTime=%time: =0%"
echo "Initial Start:    %startTime%" & echo/

(CALL node test_node_script.js) && ( 
  set "endTime=%time: =0%"
  echo "Initial End:      %endTime%"

  rem Get elapsed time:
  set "end=!endTime:%time:~8,1%=%%100)*100+1!"  &  set "start=!startTime:%time:~8,1%=%%100)*100+1!"

  set /A "elap=((((10!end:%time:~2,1%=%%100)*60+1!%%100)-((((10!start:%time:~2,1%=%%100)*60+1!%%100), elap-=(elap>>31)*24*60*60*100"
  set /A "totalTime=elap/100"
  echo "Elaps time: %totalTime%" & echo/

  rem Convert elapsed time to HH:MM:SS:CC format:
  set /A "cc=elap%%100+100,elap/=100,ss=elap%%60+100,elap/=60,mm=elap%%60+100,hh=elap/60+100"

  echo "Start:    %startTime%" & echo/
  echo "End:      %endTime%" & echo/
  echo "Elapsed:  %hh:~1%%time:~2,1%%mm:~1%%time:~2,1%%ss:~1%%time:~8,1%%cc:~1%" & echo/

) || (
  echo "script failed" & echo/
)

the example node script(test_node_script.js):

async function init() {
  console.log(1);
  await sleep(1000);
  console.log(2);
}

function sleep(ms) {
  return new Promise((resolve) => {
    setTimeout(resolve, ms);
  });
}

init()

The issue is that the endTime is not being set in the batch file for some reason. Here's the output that I see in the cmd:

"Starting the script run...."

"Initial Start:    16:45:28.56"

1
2
"Initial End:      "
"Elaps time: 0"

"Start:    16:45:28.56"

"End:      "

"Elapsed:  00:00:00.00"

How do I get the endTime so this calculation works?

Answer 1

From my library:

@rem Taken from https://stackoverflow.com/a/6209392/3150445 and modified to allow composability
@rem and to eliminate the ~1..2cs overhead of loading another instance of cmd.exe.

@if "%1" equ "-?" goto :ShowHelpAndExit
@if "%1" equ "/?" goto :ShowHelpAndExit

@rem Measure the time to run whatever is on the command line.
@set _start_=%time%
@call %*
@set _CmdErrorLevel_=%ERRORLEVEL%
@set _end_=%time%

@call :OutputElapsedTime

@rem Clean-up and return the result from whatever we just timed for the caller.
@rem We could not put everything within a setlocal block and preserve the
@rem effects caused by whatever is in %*.
@set _start_=
@set _end_=
@set _CmdErrorLevel_=&exit /b %_CmdErrorLevel_%&

:OutputElapsedTime
@setlocal

@rem Break _start_ and _end_ into seperate hour, minute, second and centisecond values.
@rem _options_ works in locales that use period or comma for decimal fractions.
@set _options_="tokens=1-4 delims=:.,"
@for /f %_options_% %%a in ("%_start_%") do @call :SplitTime _start %%a %%b %%c %%d
@for /f %_options_% %%a in ("%_end_%") do @call :SplitTime _end %%a %%b %%c %%d

@rem Calculate the run-time.
@set /a _hours_=%_end_h_%-%_start_h_%
@set /a _mins_=%_end_m_%-%_start_m_%
@set /a _secs_=%_end_s_%-%_start_s_%
@set /a _cs_=%_end_cs_%-%_start_cs_%

@rem Correct for under-flows.
@if %_cs_% lss 0 @set /a _secs_ = %_secs_% - 1 &@set /a _cs_ = 100%_cs_%
@if %_secs_% lss 0 @set /a _mins_ = %_mins_% - 1 &@set /a _secs_ = 60%_secs_%
@if %_mins_% lss 0 @set /a _hours_ = %_hours_% - 1 &@set /a _mins_ = 60%_mins_%
@if %_hours_% lss 0 @set /a _hours_ = 24%_hours_%

@rem Zero padd the centiseconds if needed.
@if 1%_cs_% lss 100 @set _cs_=0%_cs_%

@rem Display summary results.
@set /a _totalsecs = %_hours_%*3600 + %_mins_%*60 + %_secs_%
@echo.
@echo TimeIt Result: %_hours_%:%_mins_%:%_secs_%.%_cs_% (%_totalsecs%.%_cs_%s total)
@if %_totalsecs% equ 0 (
  @if %_cs_% equ 0 (
    @echo An all zero result indicates command took less that 1/100 of a second.
  )
)
@exit /b 0

:ShowHelpAndExit
@set _HelpFile=%~dpn0.cmd.help.txt
@if exist %_HelpFile% (@type %_HelpFile%) else (@echo Help file %_HelpFile% not found. &_HelpFile=&exit /b %_ERROR_FILE_NOT_FOUND_%)
@exit /b %_ERROR_SUCCESS_%

@rem Takes a prefix string, hours, minutes, seconds and centiseconds parameters
@rem and sets prefix_h, prefix_m, prefix_s and prefix_cs_ environment variables.
:SplitTime
@set %1_h_=%2
@set /a %1_m_=100%3 %% 100
@set /a %1_s_=100%4 %% 100
@set /a %1_cs_=100%5 %% 100
@exit /b 0

Save the above as timeit.cmd then save the following readme as timeit.cmd.help.txt:

TimeIt.cmd Help

Description:
Runs whatever is passed on the command line, times the execution and prints
the elapsed time. Can be run from the command line or within a script.  All
side effects (environment variables) of the command(s) are preserved and the
status value returned.

Arguments:
/?
-? Spew this help content.

Everything else is passed to a `call %*` as-is and the ERRORVALUE
returned to caller.

Usage: TimeIt.cmd <whatever needs to be timed>