%time% not expanding in a for loop even with EnableDelayedExpansion

Question

So I have noticed that the %time% variable is not accurate in logs of the batch file like the one below. Output is included below the code... It picks up the current time when it enters the for loop but does not update it as it goes. These are large zip files and sometimes take several minutes to unzip each. Anyone have an idea what is going on here?

Code:

@echo off
setlocal EnableDelayedExpansion

for /f "tokens=1-26 delims=/:. " %%a in ('echo %date% %time%') do set today=%%d%%b%%c
echo %date% %time% process start >> h:\logfiles\unzip\%today%.log

:BANK1
set bank=BANK1
call:process BANK1LOCKBOX.lbx.6*.zip
call:process BANK1LOCKBOX.lbx.3*.zip

:BANK2
set bank=BANK2
call:process BANK2LOCKBOX.A*.zip PASSWORD1
call:process BANK2LOCKBOX.R*.zip PASSWORD2

echo %date% %time% process complete >> h:\logfiles\unzip\%today%.log
goto:eof

:process
set thisfile=%1
set pword=-y
if not [%2] equ [] set pword=-p%2 -y
if exist f:\banks\%bank%\zipped\%thisfile% (
    echo    %time% %thisfile% begin >> h:\logfiles\unzip\%today%.log
    for /f "tokens=1-2 delims=;" %%a in ('dir /b f:\banks\%bank%\zipped\%thisfile%') do (
        echo        %time% %%a start >> h:\logfiles\unzip\%today%.log
        7z x f:\banks\%bank%\zipped\%%a -of:\banks\%bank%\* %pword%
        if %errorlevel%==0 (
            move /y f:\banks\%bank%\zipped\%%a f:\banks\%bank%\processed\
            echo        %time% %%a complete >> h:\logfiles\unzip\%today%.log
        )
    )
    if exist f:\banks\%bank%\zipped\%thisfile% (
        move /y f:\banks\%bank%\zipped\%thisfile% f:\banks\%bank%\unprocessed\
        echo        %time% %thisfile% failed >> h:\logfiles\unzip\%today%.log
    )
    echo    %time% %thisfile% end >> h:\logfiles\unzip\%today%.log
)

And the logs look like this:

Tue 07/02/2013 10:40:55.70 process start 
    10:40:55.72 BANK1LOCKBOX.lbx.6*.zip begin 
        10:40:55.72 BANK1LOCKBOX.lbx.60.zip start 
        10:40:55.72 BANK1LOCKBOX.lbx.60.zip complete 
        10:40:55.72 BANK1LOCKBOX.lbx.64.zip start 
        10:40:55.72 BANK1LOCKBOX.lbx.64.zip complete 
    10:40:55.72 BANK1LOCKBOX.lbx.6*.zip end 
    10:41:14.02 BANK1LOCKBOX.lbx.3*.zip begin 
        10:41:14.02 BANK1LOCKBOX.lbx.391.zip start 
        10:41:14.02 BANK1LOCKBOX.lbx.391.zip complete 
        10:41:14.02 BANK1LOCKBOX.lbx.343.zip start 
        10:41:14.02 BANK1LOCKBOX.lbx.343.zip complete 
    10:41:14.02 BANK1LOCKBOX.lbx.3*.zip end 
    10:42:48.28 BANK2LOCKBOX.A*.zip begin 
        10:42:48.28 BANK2LOCKBOX.A_0_1.zip start 
        10:42:48.28 BANK2LOCKBOX.A_0_1.zip complete 
        10:42:48.28 BANK2LOCKBOX.A_6_1.zip start 
        10:42:48.28 BANK2LOCKBOX.A_6_1.zip complete 
        10:42:48.28 BANK2LOCKBOX.A_2_1.zip start 
        10:42:48.28 BANK2LOCKBOX.A_2_1.zip complete 
    10:42:48.28 BANK2LOCKBOX.A*.zip end 
    10:44:42.33 BANK2LOCKBOX.R*.zip begin 
        10:44:42.33 BANK2LOCKBOX.R_1359_1.zip start 
        10:44:42.33 BANK2LOCKBOX.R_1359_1.zip complete 
        10:44:42.33 BANK2LOCKBOX.R_1365_1.zip start 
        10:44:42.33 BANK2LOCKBOX.R_1365_1.zip complete 
        10:44:42.33 BANK2LOCKBOX.R_1371_1.zip start 
        10:44:42.33 BANK2LOCKBOX.R_1371_1.zip complete 
    10:44:42.33 BANK2LOCKBOX.R*.zip end 
Tue 07/02/2013 10:45:25.91 process complete

And as soon as I ask, I stumble on the answer... Updated all the %time% vars in the :process step to !time!, and they update as expected. — Rob Biggs, Jul 03 '13 at 23:03

Magoo · Answer 1 · 2023-01-17T15:16:57.000

2

%time% like any other %var% is evaluated at parse time. That value is then substituted for execution, thus it does not vary.

If you want the current time, you need to setlocal enabledelayedexpansion AND use !time! in place of %time%

edited Jan 17 '23 at 15:16

answered Jul 03 '13 at 23:23

Magoo

77,302
8
62
84

%time% not expanding in a for loop even with EnableDelayedExpansion

1 Answers1